[ 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 528142587 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, 524592K 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.001015] APIC: Switch to symmetric I/O mode setup [ 0.002386] x2apic enabled [ 0.003013] Switched APIC routing to physical x2apic. [ 0.004024] kvm-guest: setup PV IPIs [ 0.007502] ..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.008030] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009022] pid_max: default: 32768 minimum: 301 [ 0.010202] LSM: Security Framework initializing [ 0.011078] Yama: becoming mindful. [ 0.012068] SELinux: Initializing. [ 0.013100] *** VALIDATE selinux *** [ 0.021434] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026240] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.027189] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028139] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029151] *** VALIDATE tmpfs *** [ 0.030528] *** VALIDATE proc *** [ 0.031310] *** VALIDATE cgroup *** [ 0.032017] *** VALIDATE cgroup2 *** [ 0.033328] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034193] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.036011] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037044] Spectre V2 : User space: Vulnerable [ 0.038018] Speculative Store Bypass: Vulnerable [ 0.041663] debug: unmapping init [mem 0xffffffffbac59000-0xffffffffbac60fff] [ 0.043204] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044782] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045026] ... version: 2 [ 0.046015] ... bit width: 48 [ 0.047021] ... generic registers: 4 [ 0.048020] ... value mask: 0000ffffffffffff [ 0.049022] ... max period: 00007fffffffffff [ 0.050023] ... fixed-purpose events: 3 [ 0.051020] ... event mask: 000000070000000f [ 0.052380] rcu: Hierarchical SRCU implementation. [ 0.054748] smp: Bringing up secondary CPUs ... [ 0.055676] x86: Booting SMP configuration: [ 0.056043] .... node #0, CPUs: #1 #2 #3 [ 0.062135] smp: Brought up 1 node, 4 CPUs [ 0.064023] smpboot: Max logical packages: 1 [ 0.065017] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.239043] node 0 deferred pages initialised in 171ms [ 0.242140] devtmpfs: initialized [ 0.243392] x86/mm: Memory block size: 128MB [ 0.245440] gcov: version magic: 0x41383552 [ 0.248210] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.253081] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.254293] pinctrl core: initialized pinctrl subsystem [ 0.256133] [ 0.256509] ************************************************************* [ 0.258012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.261015] ** ** [ 0.263015] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.265015] ** ** [ 0.268015] ** This means that this kernel is built to expose internal ** [ 0.270012] ** IOMMU data structures, which may compromise security on ** [ 0.273015] ** your system. ** [ 0.276022] ** ** [ 0.278016] ** If you see this message and you are not debugging the ** [ 0.280014] ** kernel, report this immediately to your vendor! ** [ 0.283015] ** ** [ 0.285013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.288013] ************************************************************* [ 0.290711] NET: Registered protocol family 16 [ 0.292567] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.295067] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.299071] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.303039] cpuidle: using governor menu [ 0.304754] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.306706] PCI: Using configuration type 1 for base access [ 0.309138] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.319098] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.322034] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.325081] cryptd: max_cpu_qlen set to 1000 [ 0.327219] ACPI: Added _OSI(Module Device) [ 0.329013] ACPI: Added _OSI(Processor Device) [ 0.330013] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.332014] ACPI: Added _OSI(Processor Aggregator Device) [ 0.337450] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.343775] ACPI: Interpreter enabled [ 0.345060] ACPI: PM: (supports S0 S3 S4 S5) [ 0.346062] ACPI: Using IOAPIC for interrupt routing [ 0.348103] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.351461] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.365488] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.368046] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.370021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.374090] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.379576] acpiphp: Slot [2] registered [ 0.381233] acpiphp: Slot [5] registered [ 0.382123] acpiphp: Slot [6] registered [ 0.384133] acpiphp: Slot [7] registered [ 0.385254] acpiphp: Slot [8] registered [ 0.387099] acpiphp: Slot [9] registered [ 0.389125] acpiphp: Slot [10] registered [ 0.390128] acpiphp: Slot [3] registered [ 0.391080] acpiphp: Slot [4] registered [ 0.392074] acpiphp: Slot [11] registered [ 0.394101] acpiphp: Slot [12] registered [ 0.395109] acpiphp: Slot [13] registered [ 0.397100] acpiphp: Slot [14] registered [ 0.398132] acpiphp: Slot [15] registered [ 0.400120] acpiphp: Slot [16] registered [ 0.401104] acpiphp: Slot [17] registered [ 0.403181] acpiphp: Slot [18] registered [ 0.405153] acpiphp: Slot [19] registered [ 0.406145] acpiphp: Slot [20] registered [ 0.408105] acpiphp: Slot [21] registered [ 0.409083] acpiphp: Slot [22] registered [ 0.411084] acpiphp: Slot [23] registered [ 0.412096] acpiphp: Slot [24] registered [ 0.413163] acpiphp: Slot [25] registered [ 0.415085] acpiphp: Slot [26] registered [ 0.416159] acpiphp: Slot [27] registered [ 0.418115] acpiphp: Slot [28] registered [ 0.419147] acpiphp: Slot [29] registered [ 0.421099] acpiphp: Slot [30] registered [ 0.423061] acpiphp: Slot [31] registered [ 0.424067] PCI host bridge to bus 0000:00 [ 0.424952] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.427014] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.429026] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.433024] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.436023] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.439024] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.441014] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.444358] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.447425] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.457805] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.463509] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.466021] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.469021] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.472020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.476589] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.479867] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.482031] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.483851] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.489013] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.503016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.509017] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.515075] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.525017] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.533019] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.552020] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.565212] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.583027] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.597026] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.636019] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.653662] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.668125] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.686023] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.710021] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.729107] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.740020] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.761068] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.776020] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.801450] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.811026] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.823022] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.846014] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.864532] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.881028] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.898017] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.919019] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.932355] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.937498] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.940520] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.942384] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.945342] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.949217] iommu: Default domain type: Passthrough [ 0.950811] SCSI subsystem initialized [ 0.952272] ACPI: bus type USB registered [ 0.954654] usbcore: registered new interface driver usbfs [ 0.957111] usbcore: registered new interface driver hub [ 0.960154] usbcore: registered new device driver usb [ 0.962229] pps_core: LinuxPPS API ver. 1 registered [ 0.963011] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.967106] PTP clock support registered [ 0.969214] EDAC MC: Ver: 3.0.0 [ 0.971213] PCI: Using ACPI for IRQ routing [ 0.972898] NetLabel: Initializing [ 0.973011] NetLabel: domain hash size = 128 [ 0.974010] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.975181] NetLabel: unlabeled traffic allowed by default [ 0.977407] vgaarb: loaded [ 0.978377] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.980015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.988616] clocksource: Switched to clocksource kvm-clock [ 1.112398] VFS: Disk quotas dquot_6.6.0 [ 1.114178] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.116677] *** VALIDATE ramfs *** [ 1.117610] *** VALIDATE hugetlbfs *** [ 1.119337] pnp: PnP ACPI init [ 1.121470] pnp: PnP ACPI: found 6 devices [ 1.137882] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.140768] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.142463] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.144475] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.147259] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.150065] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.153713] NET: Registered protocol family 2 [ 1.156353] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.161527] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.167430] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.174045] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.178619] TCP: Hash tables configured (established 65536 bind 65536) [ 1.182934] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.185873] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.187736] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.193076] NET: Registered protocol family 1 [ 1.195437] RPC: Registered named UNIX socket transport module. [ 1.201169] RPC: Registered udp transport module. [ 1.202409] RPC: Registered tcp transport module. [ 1.203492] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.205285] NET: Registered protocol family 44 [ 1.206964] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.208992] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.210864] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.212967] PCI: CLS 0 bytes, default 64 [ 1.214133] Unpacking initramfs... [ 2.693101] debug: unmapping init [mem 0xffff91527cc54000-0xffff91527ffbffff] [ 2.699067] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.701022] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.704560] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.216758] Initialise system trusted keyrings [ 3.218523] Key type blacklist registered [ 3.220484] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.229813] zbud: loaded [ 3.233727] *** VALIDATE nfs *** [ 3.235051] *** VALIDATE nfs4 *** [ 3.238362] pstore: using deflate compression [ 3.241755] Platform Keyring initialized [ 3.341250] NET: Registered protocol family 38 [ 3.343525] Key type asymmetric registered [ 3.345089] Asymmetric key parser 'x509' registered [ 3.347387] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.350822] io scheduler mq-deadline registered [ 3.352603] io scheduler kyber registered [ 3.354413] io scheduler bfq registered [ 3.357877] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.360230] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.362494] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.364786] ACPI: Power Button [PWRF] [ 3.369662] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.375823] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.388213] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.397488] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.417880] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.445780] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.476758] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.481256] Non-volatile memory driver v1.3 [ 3.482772] Linux agpgart interface v0.103 [ 3.516237] virtio_blk virtio1: [vda] 145784 512-byte logical blocks (74.6 MB/71.2 MiB) [ 3.519046] vda: detected capacity change from 0 to 74641408 [ 3.538590] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.541117] vdb: detected capacity change from 0 to 1073741824 [ 3.555973] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.558930] vdc: detected capacity change from 0 to 2621440000 [ 3.572910] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.575166] vdd: detected capacity change from 0 to 2621440000 [ 3.588120] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.590392] vde: detected capacity change from 0 to 4294967296 [ 3.604860] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.607421] vdf: detected capacity change from 0 to 4294967296 [ 3.612675] libphy: Fixed MDIO Bus: probed [ 3.625250] usbcore: registered new interface driver usbserial_generic [ 3.626922] usbserial: USB Serial support registered for generic [ 3.628862] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.633361] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.634786] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.636990] mousedev: PS/2 mouse device common for all mice [ 3.639278] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.642578] rtc_cmos 00:05: RTC can wake from S4 [ 3.644956] rtc_cmos 00:05: registered as rtc0 [ 3.646348] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.648104] intel_pstate: CPU model not supported [ 3.651879] hid: raw HID events driver (C) Jiri Kosina [ 3.653741] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.657081] usbcore: registered new interface driver usbhid [ 3.659232] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.671693] usbhid: USB HID core driver [ 3.675282] drop_monitor: Initializing network drop monitor service [ 3.677301] Initializing XFRM netlink socket [ 3.679225] NET: Registered protocol family 10 [ 3.682912] Segment Routing with IPv6 [ 3.684436] NET: Registered protocol family 17 [ 3.686299] mpls_gso: MPLS GSO support [ 3.693557] RAS: Correctable Errors collector initialized. [ 3.697024] AVX version of gcm_enc/dec engaged. [ 3.699889] AES CTR mode by8 optimization enabled [ 3.800282] sched_clock: Marking stable (3800240829, 0)->(4808638375, -1008397546) [ 3.806104] registered taskstats version 1 [ 3.810779] Loading compiled-in X.509 certificates [ 3.813931] zswap: loaded using pool lzo/zbud [ 3.897926] Key type big_key registered [ 3.920523] Key type encrypted registered [ 3.922516] ima: No TPM chip found, activating TPM-bypass! [ 3.924825] ima: Allocated hash algorithm: sha1 [ 3.926946] ima: No architecture policies found [ 3.928593] evm: Initialising EVM extended attributes: [ 3.930763] evm: security.selinux [ 3.931984] evm: security.ima [ 3.932794] evm: security.capability [ 3.933763] evm: HMAC attrs: 0x1 [ 3.935637] rtc_cmos 00:05: setting system clock to 2026-07-18 19:29:54 UTC (1784402994) [ 3.941613] debug: unmapping init [mem 0xffffffffbbc03000-0xffffffffbbdfffff] [ 3.945162] debug: unmapping init [mem 0xffffffffba982000-0xffffffffbac58fff] [ 3.952334] Write protecting the kernel read-only data: 28672k [ 3.955662] debug: unmapping init [mem 0xffffffffb9003000-0xffffffffb91fffff] [ 3.957810] debug: unmapping init [mem 0xffffffffb9914000-0xffffffffb99fffff] [ 3.990087] 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.995904] systemd[1]: Detected virtualization kvm. [ 3.997273] systemd[1]: Detected architecture x86-64. [ 3.998527] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.022578] systemd[1]: No hostname configured. [ 4.023996] systemd[1]: Set hostname to . [ 4.025468] random: systemd: uninitialized urandom read (16 bytes read) [ 4.027112] systemd[1]: Initializing machine ID from random generator. [ 4.087922] random: ln: uninitialized urandom read (6 bytes read) [ 4.189131] random: systemd: uninitialized urandom read (16 bytes read) [ 4.191858] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 4.199941] systemd[1]: Started Memstrack Anylazing Service. [ OK ] Started Memstrack Anylazing Service. [ 4.222807] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Timers. [ OK ] Reached target Slices. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Initrd Root Device. Starting Apply Kernel Variables... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Reached target Swap. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Paths. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ 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... [ 5.117117] device-mapper: uevent: version 1.0.3 [ 5.119446] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [[ 6.273270] random: fast init done  OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 6.402077] virtio_net virtio0 ens2: renamed from eth0 [ 6.629504] scsi host0: ata_piix [ 6.811564] scsi host1: ata_piix [ 6.866271] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 6.868468] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 11.454920] random: crng init done [ 11.458870] random: 7 urandom warning(s) missed due to ratelimiting [ 13.900508] dracut-initqueue[579]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 16.458373] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Timers. [ 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 target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 19.708182] printk: systemd: 25 output lines suppressed due to ratelimiting [ 20.862465] SELinux: Disabled at runtime. [ 21.007327] 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) [ 21.038610] systemd[1]: Detected virtualization kvm. [ 21.054733] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 23.216560] systemd[1]: initrd-switch-root.service: Succeeded. [ 23.228292] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 23.267866] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 23.281135] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 23.286742] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 23.317365] systemd[1]: Starting Journal Service... Starting Journal Service... [ 23.338377] systemd[1]: Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting POSIX Message Queue File System... Mounting Huge Pages File System... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Starting Apply Kernel Variables... [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-getty.slice. Mounting Kernel Debug File System... [ OK ] Listening on Process Core Dump Socket. [ OK ] Stopped target Switch Root. Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-serial\x2dgetty.slice. [ 23.777302] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting udev Coldplug all Devices... [ OK ] Stopped target Initrd Root File System. Starting Create list of required st…ce nodes for the current kernel... Starting Remount Root and Kernel File Systems... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Stopped target Initrd File Systems. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 25.336286] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 26.619698] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 26.967579] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 27.473747] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 27.578120] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit)[ 31.547922] Key type dns_resolver registered [** ] A start job is running for Configur…-only root support (8s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit)[ 32.492760] NFS: Registering the id_resolver key type [ 32.495046] Key type id_resolver registered [ 32.496477] Key type id_legacy registered [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Load/Save Random Seed. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. Starting Login Service... [ OK ] Started irqbalance daemon. [ OK ] Started D-Bus System Message Bus. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started Login Service. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg258-server login: [ 49.739019] hrtimer: interrupt took 22694476 ns [ 95.741577] libcfs: loading out-of-tree module taints kernel. [ 95.784405] Key type ._llcrypt registered [ 95.786525] Key type .llcrypt registered [ 95.867241] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_hostid [ 113.398906] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 115.145848] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 115.164035] alg: No test for adler32 (adler32-zlib) [ 116.792885] Lustre: Lustre: Build Version: 2.17.54_174_g53e1600 [ 117.858834] LNet: Added LNI 192.168.202.158@tcp [8/256/0/180] [ 119.720127] Key type lgssc registered [ 121.848137] Lustre: Echo OBD driver; http://www.lustre.org/ [ 142.558844] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 189.574809] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 205.568555] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 205.597699] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 207.055382] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 207.114248] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 207.212641] Lustre: lustre-MDT0000: new disk, initializing [ 207.320849] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 207.360950] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 212.203821] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 227.902339] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 228.092932] Lustre: 6511: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 [ 228.161473] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 228.170738] Lustre: Skipped 1 previous similar message [ 228.289740] Lustre: lustre-MDT0001: new disk, initializing [ 228.366915] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 228.405236] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 228.430876] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 234.011588] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 239.529851] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 251.536891] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 251.829517] Lustre: lustre-OST0000: new disk, initializing [ 251.833857] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 251.839670] Lustre: 8452:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 251.935681] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 258.090862] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 258.104686] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 258.174457] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 259.885629] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 277.879552] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 278.074161] Lustre: lustre-OST0001: new disk, initializing [ 278.083508] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 278.087877] Lustre: 9524:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 278.197488] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 286.828201] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 286.860963] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 287.126686] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 287.615237] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 303.124821] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 314.305693] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 322.766799] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing check_logdir /tmp/testlogs/ [ 329.410866] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing yml_node [ 335.763943] Lustre: DEBUG MARKER: Client: 2.17.54.174 [ 339.234557] Lustre: DEBUG MARKER: MDS: 2.17.54.174 [ 343.394430] Lustre: DEBUG MARKER: OSS: 2.17.54.174 [ 346.093645] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Sat Jul 18 15:35:33 EDT 2026 [ 369.768687] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 386.576334] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 399.857316] 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 [ 399.859759] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 399.886440] Lustre: Skipped 3 previous similar messages [ 399.911097] Lustre: Skipped 3 previous similar messages [ 404.978794] Lustre: server umount lustre-MDT0000 complete [ 410.084356] LustreError: 7940:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 410.130414] LustreError: 7940:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 415.205213] LustreError: 6523:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 415.231334] LustreError: 6523:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 3 previous similar messages [ 416.807582] LustreError: 7460:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784403407 with bad export cookie 3909618556098429414 [ 416.810866] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 416.833946] LustreError: 7460:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 417.377195] Lustre: server umount lustre-MDT0001 complete [ 435.680299] Lustre: 3644:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784403410/real 1784403410] req@ffff915301096300 x1871082273495296/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784403426 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 435.737862] 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 [ 436.704983] Lustre: 3646:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784403411/real 1784403411] req@ffff9152ff523800 x1871082273495552/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784403427 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 440.864508] Lustre: 3644:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784403415/real 1784403415] req@ffff9152ff520e00 x1871082273495808/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784403431 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 442.154051] Lustre: server umount lustre-OST0000 complete [ 442.913138] Lustre: 3646:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784403417/real 1784403417] req@ffff9152ff522a00 x1871082273496192/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784403433 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 447.968206] Lustre: 3645:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784403422/real 1784403422] req@ffff9152ca688700 x1871082273496448/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784403438 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 453.702844] Lustre: server umount lustre-OST0001 complete [ 475.450126] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing unload_modules_local [ 479.840431] Key type lgssc unregistered [ 480.292774] LNet: 14826:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 480.300366] LNetError: 14826:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 480.360512] LNet: Removed LNI 192.168.202.158@tcp [ 481.817343] Key type .llcrypt unregistered [ 481.823078] Key type ._llcrypt unregistered [ 513.027688] Key type ._llcrypt registered [ 513.029624] Key type .llcrypt registered [ 513.141504] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_hostid [ 531.743717] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 534.180069] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 534.336069] alg: No test for adler32 (adler32-zlib) [ 535.652237] Lustre: Lustre: Build Version: 2.17.54_174_g53e1600 [ 536.140463] LNet: Added LNI 192.168.202.158@tcp [8/256/0/180] [ 537.932454] Key type lgssc registered [ 539.760903] Lustre: Echo OBD driver; http://www.lustre.org/ [ 602.040963] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 620.113638] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 620.175812] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 621.627352] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 621.691270] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 621.796503] Lustre: lustre-MDT0000: new disk, initializing [ 621.914986] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 621.944189] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 627.421775] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 644.361477] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 644.461711] Lustre: 19288: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 [ 644.508414] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 644.515253] Lustre: Skipped 1 previous similar message [ 644.612306] Lustre: lustre-MDT0001: new disk, initializing [ 644.716755] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 644.759629] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 644.786128] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 650.418607] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 656.248596] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 668.114860] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 668.513169] Lustre: lustre-OST0000: new disk, initializing [ 668.519677] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 668.524670] Lustre: 21229:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 668.529880] Lustre: lustre-OST0000: Not available for connect from 0@lo (not set up) [ 668.591121] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 673.872103] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 673.879286] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 673.937681] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000400 [ 676.234267] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 692.865035] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 692.977621] Lustre: lustre-OST0001: new disk, initializing [ 692.980755] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 692.985172] Lustre: 22255:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 693.040383] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 700.582237] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 702.564369] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 702.584828] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 702.670747] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 714.801186] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 722.696489] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 733.154499] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 15:42:01 (1784403721) === [ 736.006219] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 15:42:04 (1784403724) [ 736.238264] Lustre: 19296:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 736.251777] Lustre: 19296:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 736.257901] Lustre: 19296:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 736.268252] Lustre: 19296:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 736.280267] Lustre: 19296:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 736.304054] Lustre: 19296:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 736.829873] Lustre: 19294:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 736.836517] Lustre: 19294:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 11 previous similar messages [ 736.843536] Lustre: 19294:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 736.849039] Lustre: 19294:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 736.853838] Lustre: 19294:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 736.860646] Lustre: 19294:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 736.865301] Lustre: 19294:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 736.875919] Lustre: 19294:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 736.887555] Lustre: 19294:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 736.897584] Lustre: 19294:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 736.902394] Lustre: 19294:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 736.906139] Lustre: 19294:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 737.851741] Lustre: 21457:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 737.857847] Lustre: 21457:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 59 previous similar messages [ 737.861890] Lustre: 21457:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 737.865944] Lustre: 21457:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 737.869811] Lustre: 21457:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 737.874708] Lustre: 21457:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 737.879276] Lustre: 21457:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 737.884090] Lustre: 21457:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 737.888644] Lustre: 21457:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 737.894232] Lustre: 21457:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 737.936182] Lustre: 21457:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 737.940339] Lustre: 21457:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 739.854840] Lustre: 19294:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 739.863621] Lustre: 19294:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 101 previous similar messages [ 739.870552] Lustre: 19294:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 739.878859] Lustre: 19294:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 739.888604] Lustre: 19294:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 739.898092] Lustre: 19294:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 739.904741] Lustre: 19294:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 739.911685] Lustre: 19294:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 739.918890] Lustre: 19294:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 739.925778] Lustre: 19294:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 740.006968] Lustre: 19294:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 740.014968] Lustre: 19294:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 744.083566] Lustre: *** cfs_fail_loc=1600, val=3*** [ 747.104190] Lustre: *** cfs_fail_loc=1600, val=3*** [ 747.177808] Lustre: 21218:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 747.180906] Lustre: 21219:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 747.194889] Lustre: 21218:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 102 previous similar messages [ 747.194935] Lustre: 21218:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 747.194940] Lustre: 21218:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 747.194946] Lustre: 21218:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 747.194949] Lustre: 21218:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 747.194954] Lustre: 21218:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 747.194957] Lustre: 21218:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 101 previous similar messages [ 747.194962] Lustre: 21218:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 747.194964] Lustre: 21218:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 98 previous similar messages [ 747.305875] Lustre: 21219:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 103 previous similar messages [ 749.206201] Lustre: *** cfs_fail_loc=1600, val=3*** [ 758.704890] Lustre: 23674:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 758.712250] Lustre: 23692:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 758.719035] Lustre: 23674:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 65 previous similar messages [ 758.719062] Lustre: 23674:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 758.719066] Lustre: 23674:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 65 previous similar messages [ 758.719072] Lustre: 23674:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 758.719076] Lustre: 23674:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 65 previous similar messages [ 758.719081] Lustre: 23674:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 758.719084] Lustre: 23674:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 65 previous similar messages [ 758.719090] Lustre: 23674:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 758.719093] Lustre: 23674:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 65 previous similar messages [ 758.781635] Lustre: 23692:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 762.340903] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 762.357699] 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 [ 762.379600] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 764.397058] 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 [ 764.422474] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 764.424092] Lustre: Skipped 1 previous similar message [ 764.434967] Lustre: Skipped 3 previous similar messages [ 767.508541] Lustre: server umount lustre-MDT0000 complete [ 771.676462] LustreError: 19281:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784403762 with bad export cookie 2760266335283875770 [ 771.687127] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 771.687592] LustreError: 19281:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 772.186749] Lustre: server umount lustre-MDT0001 complete [ 787.045573] Lustre: server umount lustre-OST0000 complete [ 791.072222] Lustre: 16447:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784403765/real 1784403765] req@ffff9151c9786d80 x1871082711793152/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784403781 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 791.126335] 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 [ 791.146485] Lustre: Skipped 1 previous similar message [ 791.931762] Lustre: server umount lustre-OST0001 complete [ 801.010930] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 15:43:09 (1784403789) [ 817.383158] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 830.470802] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 831.020203] LustreError: 26260:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 831.047789] LustreError: 26260:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 5 previous similar messages [ 831.115866] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 836.577873] LustreError: 26261:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 836.999911] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 840.676632] LustreError: 26260:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 845.799874] LustreError: 26261:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 846.843406] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 847.317245] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 852.584100] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 856.292973] Lustre: 27403:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 864.246674] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 864.526127] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 871.737161] LustreError: 27755:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 873.253432] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 875.847063] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:40 to 0x280000400:65) [ 881.137326] LustreError: 27756:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 881.161291] LustreError: 27756:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 3 previous similar messages [ 883.779663] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 889.326802] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 891.530858] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 900.142978] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 904.403775] Lustre: 29278:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 906.098722] Lustre: 26257:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 906.116166] Lustre: 26257:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 3 previous similar messages [ 906.121049] Lustre: 26257:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 906.125868] Lustre: 26257:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1 previous similar message [ 906.130376] Lustre: 26257:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 906.136125] Lustre: 26257:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 906.146668] Lustre: 26257:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 906.153171] Lustre: 26257:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 906.157456] Lustre: 26257:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 906.162437] Lustre: 26257:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 906.168359] Lustre: 26257:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 906.176508] Lustre: 26257:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 912.239671] Lustre: *** cfs_fail_loc=1501, val=0*** [ 921.901732] Lustre: Failing over lustre-MDT0000 [ 922.362873] Lustre: server umount lustre-MDT0000 complete [ 924.129235] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 924.135275] 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 [ 924.147984] LustreError: 26261:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 935.228553] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 935.550430] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 935.917862] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 935.920813] Lustre: Skipped 1 previous similar message [ 935.967380] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 941.047656] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 941.098613] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 941.157894] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 941.224707] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 941.225187] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 941.499821] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 946.440332] Lustre: *** cfs_fail_loc=1505, val=0*** [ 955.676448] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 15:45:43 (1784403943) [ 957.184686] Lustre: 26257:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 957.191569] Lustre: 26257:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 322 previous similar messages [ 957.200494] Lustre: 26257:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 957.207838] Lustre: 26257:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 957.218302] Lustre: 26257:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 957.229894] Lustre: 26257:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 957.240196] Lustre: 26257:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 957.256410] Lustre: 26257:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 957.266861] Lustre: 26257:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 957.274755] Lustre: 26257:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 957.284039] Lustre: 26257:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 957.291909] Lustre: 26257:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 964.351934] Lustre: *** cfs_fail_loc=1502, val=0*** [ 975.441392] Lustre: Failing over lustre-MDT0000 [ 975.980650] Lustre: server umount lustre-MDT0000 complete [ 976.866739] 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 [ 976.883172] LustreError: 28585:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 976.886238] Lustre: Skipped 5 previous similar messages [ 976.919819] LustreError: 28585:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 15 previous similar messages [ 988.892257] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 989.059370] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 989.363708] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 994.793522] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 994.794941] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 994.812062] Lustre: Skipped 3 previous similar messages [ 994.827405] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 994.878030] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 994.879204] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 995.587449] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 999.245453] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1007.769791] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 15:46:36 (1784403996) [ 1017.792325] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1017.794196] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1017.795375] Lustre: Skipped 1 previous similar message [ 1022.083302] Lustre: 27761:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 1022.088171] Lustre: 27763:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1022.093363] Lustre: 27761:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 613 previous similar messages [ 1022.093395] Lustre: 27761:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 1022.093398] Lustre: 27761:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 614 previous similar messages [ 1022.093403] Lustre: 27761:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 1022.093407] Lustre: 27761:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 614 previous similar messages [ 1022.093694] Lustre: 27761:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1022.093700] Lustre: 27761:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 614 previous similar messages [ 1022.093707] Lustre: 27761:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1022.093710] Lustre: 27761:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 614 previous similar messages [ 1022.251418] Lustre: 27763:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 629 previous similar messages [ 1028.610254] Lustre: Failing over lustre-MDT0000 [ 1028.928556] Lustre: server umount lustre-MDT0000 complete [ 1030.625169] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1030.640969] 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 [ 1030.665265] Lustre: Skipped 1 previous similar message [ 1043.470165] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1043.596374] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1043.894668] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1043.898049] Lustre: Skipped 1 previous similar message [ 1043.960111] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1049.058713] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1049.067544] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1049.076176] Lustre: Skipped 3 previous similar messages [ 1049.133289] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1049.190062] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:233 to 0x280000400:257) [ 1049.192321] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 1049.899257] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1053.842094] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1063.292285] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 15:47:31 (1784404051) [ 1070.847527] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1080.954453] Lustre: Failing over lustre-MDT0000 [ 1081.240162] Lustre: server umount lustre-MDT0000 complete [ 1084.898517] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1084.901198] 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 [ 1084.915386] LustreError: 28585:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1084.915402] LustreError: 28585:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 20 previous similar messages [ 1084.975908] Lustre: Skipped 5 previous similar messages [ 1095.729244] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1095.832946] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1096.107661] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1101.280970] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1101.310642] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1101.321789] Lustre: Skipped 3 previous similar messages [ 1101.351480] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1101.427560] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 1101.428049] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 1102.136500] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1113.070647] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 15:48:21 (1784404101) [ 1120.054896] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1128.266369] Lustre: Failing over lustre-MDT0000 [ 1128.579907] Lustre: server umount lustre-MDT0000 complete [ 1132.008859] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1132.017942] 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 [ 1132.062345] Lustre: Skipped 3 previous similar messages [ 1141.519690] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1141.684909] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1142.173673] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1147.368873] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1147.378154] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1147.388215] Lustre: Skipped 3 previous similar messages [ 1147.416371] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1147.457693] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 1147.460517] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:361 to 0x280000400:385) [ 1147.691695] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1159.241625] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 15:49:07 (1784404147) [ 1160.828637] Lustre: 26256:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1160.836213] Lustre: 26256:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 674 previous similar messages [ 1160.840642] Lustre: 26256:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1160.845662] Lustre: 26256:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 660 previous similar messages [ 1160.850191] Lustre: 26256:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1160.854260] Lustre: 26256:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 675 previous similar messages [ 1160.857820] Lustre: 26256:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1160.861739] Lustre: 26256:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 675 previous similar messages [ 1160.866596] Lustre: 26256:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1160.878822] Lustre: 26256:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 675 previous similar messages [ 1160.884552] Lustre: 26256:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1160.887555] Lustre: 26256:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 675 previous similar messages [ 1167.415390] Lustre: *** cfs_fail_loc=1605, val=0*** [ 1176.340379] Lustre: Failing over lustre-MDT0000 [ 1176.796767] Lustre: server umount lustre-MDT0000 complete [ 1178.085399] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1189.069240] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1189.195296] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1189.468677] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1189.471835] Lustre: Skipped 2 previous similar messages [ 1189.505879] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1194.492441] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1194.494785] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1194.524132] Lustre: Skipped 3 previous similar messages [ 1194.542137] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1194.607624] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:425 to 0x280000400:449) [ 1194.608868] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 1195.344198] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1205.411599] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 15:49:53 (1784404193) [ 1212.159871] Lustre: *** cfs_fail_loc=161d, val=0*** [ 1220.970583] Lustre: Failing over lustre-MDT0000 [ 1221.326778] Lustre: server umount lustre-MDT0000 complete [ 1225.192849] 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 [ 1225.206857] Lustre: Skipped 5 previous similar messages [ 1225.207717] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1225.208782] LustreError: 32561:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1225.208791] LustreError: 32561:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 31 previous similar messages [ 1232.974197] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1233.064547] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1233.385853] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1238.273498] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1238.509301] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1238.515647] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1238.521524] Lustre: Skipped 3 previous similar messages [ 1238.605692] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1238.666994] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 1238.668707] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:489 to 0x280000400:513) [ 1249.040092] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 15:50:37 (1784404237) [ 1251.828287] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1264.417796] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 15:50:52 (1784404252) [ 1270.990912] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1272.044362] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1285.644139] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 15:51:14 (1784404274) [ 1321.628251] Lustre: Failing over lustre-MDT0000 [ 1321.954468] Lustre: server umount lustre-MDT0000 complete [ 1328.301499] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1338.589817] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1339.880887] Lustre: 16446:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784404314/real 1784404314] req@ffff9152fc3b7100 x1871082712457728/t0(0) o400->MGC192.168.202.158@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1784404330 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1339.916193] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1353.099796] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1353.137157] Lustre: lustre-MDT0000: reset Object Index mappings [ 1364.455943] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x264e6f9b8012ac65 [ 1364.481973] Lustre: MGC192.168.202.158@tcp: Connection restored to 0@lo (at 0@lo) [ 1364.494692] Lustre: Skipped 3 previous similar messages [ 1365.200881] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1370.614781] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1370.662574] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1370.735952] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:592 to 0x280000400:609) [ 1370.747182] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1370.827151] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1375.074737] LustreError: 42925:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1375.106474] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1376.163714] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1377.185179] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1379.246690] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1379.248525] Lustre: Skipped 1 previous similar message [ 1387.389102] Lustre: Failing over lustre-MDT0000 [ 1387.745838] Lustre: server umount lustre-MDT0000 complete [ 1391.075772] 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 [ 1391.083367] Lustre: Skipped 7 previous similar messages [ 1391.085327] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1400.513802] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1406.489414] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1406.535522] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1406.536223] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:592 to 0x280000400:641) [ 1410.924725] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1419.333734] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 15:53:27 (1784404407) [ 1421.274240] Lustre: 28585:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1421.286743] Lustre: 28585:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1388 previous similar messages [ 1421.293912] Lustre: 28585:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1421.300746] Lustre: 28585:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1388 previous similar messages [ 1421.311678] Lustre: 28585:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1421.320033] Lustre: 28585:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1388 previous similar messages [ 1421.327368] Lustre: 28585:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1421.337860] Lustre: 28585:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1388 previous similar messages [ 1421.345795] Lustre: 28585:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1421.361020] Lustre: 28585:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1388 previous similar messages [ 1421.369715] Lustre: 28585:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1421.383399] Lustre: 28585:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1388 previous similar messages [ 1422.973129] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1434.164690] Lustre: Failing over lustre-MDT0000 [ 1434.718790] Lustre: server umount lustre-MDT0000 complete [ 1440.493325] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1452.270455] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1453.408155] Lustre: 16445:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784404427/real 1784404427] req@ffff9152fc0c4a80 x1871082712564992/t0(0) o400->MGC192.168.202.158@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1784404443 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1464.994373] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1465.016114] Lustre: lustre-MDT0000: reset Object Index mappings [ 1479.430736] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1479.434958] Lustre: Skipped 3 previous similar messages [ 1479.488669] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1479.497352] Lustre: Skipped 1 previous similar message [ 1484.557249] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1484.793166] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1484.810586] Lustre: Skipped 1 previous similar message [ 1484.813842] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1484.834213] Lustre: Skipped 8 previous similar messages [ 1484.894696] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1484.907047] Lustre: Skipped 1 previous similar message [ 1484.950198] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1484.956202] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:681 to 0x280000400:705) [ 1488.381678] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1488.384406] Lustre: Skipped 1 previous similar message [ 1496.608227] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1496.613599] Lustre: Skipped 7 previous similar messages [ 1502.273861] Lustre: Failing over lustre-MDT0000 [ 1502.627887] Lustre: server umount lustre-MDT0000 complete [ 1505.254141] LustreError: 26261:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1505.289500] LustreError: 26261:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 98 previous similar messages [ 1513.627511] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1513.777995] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1513.791616] LustreError: Skipped 2 previous similar messages [ 1518.420409] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1519.656065] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1519.657815] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:681 to 0x280000400:737) [ 1522.027662] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1522.030555] Lustre: Skipped 84 previous similar messages [ 1529.703556] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 15:55:18 (1784404518) [ 1537.619626] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1558.027582] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 15:55:46 (1784404546) [ 1570.148039] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1570.152465] Lustre: Skipped 11 previous similar messages [ 1591.608422] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 15:56:20 (1784404580) [ 1607.617851] Lustre: Failing over lustre-MDT0000 [ 1607.808304] Lustre: server umount lustre-MDT0000 complete [ 1611.749154] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1611.765264] LustreError: Skipped 1 previous similar message [ 1616.140892] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1616.434560] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1616.449530] Lustre: Skipped 1 previous similar message [ 1620.395702] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1621.480650] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1621.485497] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1621.491590] Lustre: Skipped 1 previous similar message [ 1621.504765] Lustre: Skipped 7 previous similar messages [ 1621.534232] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1621.543673] Lustre: Skipped 1 previous similar message [ 1621.590231] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:854 to 0x280000400:897) [ 1621.590272] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:853 to 0x2c0000401:897) [ 1629.460328] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 15:56:58 (1784404618) [ 1642.230302] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 1662.176841] Lustre: 52993:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1684.289323] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1687.622899] Lustre: 54129:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1694.341480] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1694.343320] Lustre: Skipped 81 previous similar messages [ 1696.847346] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1697.888096] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1698.912261] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1700.964854] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1700.966966] Lustre: Skipped 1 previous similar message [ 1702.605930] Lustre: Failing over lustre-MDT0000 [ 1702.818745] Lustre: server umount lustre-MDT0000 complete [ 1703.395911] 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 [ 1703.406699] Lustre: Skipped 14 previous similar messages [ 1712.959897] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1718.262952] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1718.840421] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:947 to 0x280000400:993) [ 1718.840964] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:946 to 0x2c0000401:961) [ 1727.812104] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 15:58:36 (1784404716) [ 1734.129788] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1739.240834] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1739.248458] Lustre: Skipped 6 previous similar messages [ 1744.352146] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 1744.359561] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1744.375497] Lustre: Skipped 3 previous similar messages [ 1744.593618] Lustre: server umount lustre-MDT0000 complete [ 1748.693074] LustreError: 26240:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784404739 with bad export cookie 2760266335284090495 [ 1748.713774] LustreError: 26240:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1749.124869] Lustre: server umount lustre-MDT0001 complete [ 1763.331299] Lustre: server umount lustre-OST0000 complete [ 1766.368302] Lustre: 16444:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784404740/real 1784404740] req@ffff9152f0e3c700 x1871082712892416/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784404756 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1768.069359] Lustre: server umount lustre-OST0001 complete [ 1775.669056] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_hostid [ 1785.152288] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 1833.871240] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 1845.303294] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1845.628652] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1845.662818] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1845.763365] Lustre: lustre-MDT0000: new disk, initializing [ 1845.886620] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1851.448751] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1862.735758] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1862.807157] Lustre: 59190: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 [ 1862.830541] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1862.834128] Lustre: Skipped 1 previous similar message [ 1862.889677] Lustre: lustre-MDT0001: new disk, initializing [ 1862.974531] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1862.988316] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1867.396089] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1872.715545] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1880.202362] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1880.490605] Lustre: lustre-OST0000: new disk, initializing [ 1880.496362] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1880.502361] Lustre: 60836:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1882.521633] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1882.532120] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1882.613814] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1887.198901] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1899.281260] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1899.387619] Lustre: lustre-OST0001: new disk, initializing [ 1899.390705] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1899.394922] Lustre: 61707:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1900.807294] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1900.817099] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1900.874169] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1906.923701] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1917.033610] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1920.970122] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1933.981798] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1933.988128] Lustre: 59196:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 264, rollback = 2 [ 1934.011427] Lustre: 59196:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 3054 previous similar messages [ 1934.024177] Lustre: 59196:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1934.046766] Lustre: 59196:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 3055 previous similar messages [ 1934.053846] Lustre: 59196:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/264/0 [ 1934.070063] Lustre: 59196:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 3055 previous similar messages [ 1934.084627] Lustre: 59196:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1934.091933] Lustre: 59196:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 3055 previous similar messages [ 1934.105520] Lustre: 59196:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 1934.119238] Lustre: 59196:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 3055 previous similar messages [ 1934.130524] Lustre: 59196:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1934.138232] Lustre: 59196:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 3055 previous similar messages [ 1935.193962] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1935.204038] Lustre: Skipped 19 previous similar messages [ 1940.429319] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1940.437044] Lustre: Skipped 15 previous similar messages [ 1958.955623] Lustre: Failing over lustre-MDT0000 [ 1959.439827] Lustre: server umount lustre-MDT0000 complete [ 1960.418260] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1960.426108] LustreError: Skipped 2 previous similar messages [ 1970.377766] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1970.550358] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1970.558506] LustreError: Skipped 3 previous similar messages [ 1970.846920] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1970.862164] Lustre: Skipped 1 previous similar message [ 1976.258601] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1976.288866] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1976.296532] Lustre: Skipped 1 previous similar message [ 1976.304825] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1976.314996] Lustre: Skipped 7 previous similar messages [ 1976.342130] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1976.350608] Lustre: Skipped 1 previous similar message [ 1976.391746] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1976.401415] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1976.403691] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1984.740859] Lustre: Failing over lustre-MDT0000 [ 1985.083504] Lustre: server umount lustre-MDT0000 complete [ 1994.681843] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1995.049812] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1995.054408] Lustre: Skipped 8 previous similar messages [ 2000.369327] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2000.426286] Lustre: *** cfs_fail_loc=160b, val=2*** [ 2000.441299] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 2000.445553] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 2006.787483] Lustre: Failing over lustre-MDT0000 [ 2007.051542] Lustre: server umount lustre-MDT0000 complete [ 2018.255700] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2023.995300] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 2023.998116] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 2024.673174] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2031.789420] Lustre: *** cfs_fail_loc=1602, val=2*** [ 2031.791263] Lustre: Skipped 1 previous similar message [ 2045.532645] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 16:03:53 (1784405033) [ 2061.599945] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 2083.041454] Lustre: 68631:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2107.868416] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2111.455217] Lustre: 69766:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2229.113138] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 16:06:57 (1784405217) [ 2279.092558] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2279.110601] Lustre: Skipped 4 previous similar messages [ 2301.541996] Lustre: *** cfs_fail_loc=160c, val=0*** [ 2301.547897] Lustre: Skipped 7 previous similar messages [ 2338.798485] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 16:08:46 (1784405326) [ 2385.123181] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2386.134241] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2386.136782] Lustre: Skipped 50 previous similar messages [ 2388.138424] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2388.140195] Lustre: Skipped 120 previous similar messages [ 2392.157194] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2392.160615] Lustre: Skipped 212 previous similar messages [ 2400.164626] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2400.166384] Lustre: Skipped 444 previous similar messages [ 2416.175612] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2416.182208] Lustre: Skipped 886 previous similar messages [ 2449.614926] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2449.616716] Lustre: Skipped 2599 previous similar messages [ 2589.689677] Lustre: 69906:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 2589.696505] Lustre: 69906:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 36843 previous similar messages [ 2589.701414] Lustre: 69906:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 2589.706533] Lustre: 69906:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 36843 previous similar messages [ 2589.713812] Lustre: 69906:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2589.718488] Lustre: 69906:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 36843 previous similar messages [ 2589.721174] Lustre: 69906:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/1, punch: 0/0/0, quota 1/3/0 [ 2589.726928] Lustre: 69906:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 36843 previous similar messages [ 2589.732327] Lustre: 69906:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 2589.739698] Lustre: 69906:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 36843 previous similar messages [ 2589.744213] Lustre: 69906:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2589.752576] Lustre: 69906:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 36843 previous similar messages [ 2658.252105] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 16:14:06 (1784405646) [ 2802.145910] 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 [ 2802.147890] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2802.168533] Lustre: Skipped 21 previous similar messages [ 2802.187237] Lustre: Skipped 3 previous similar messages [ 2804.401392] Lustre: server umount lustre-MDT0000 complete [ 2807.265376] LustreError: 59196:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2807.281230] LustreError: 59196:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 44 previous similar messages [ 2807.598888] LustreError: 59181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784405798 with bad export cookie 2760266335284109591 [ 2807.602271] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2807.608531] LustreError: 59181:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2807.617127] LustreError: Skipped 2 previous similar messages [ 2807.922809] Lustre: server umount lustre-MDT0001 complete [ 2821.684528] Lustre: server umount lustre-OST0000 complete [ 2833.795801] Lustre: server umount lustre-OST0001 complete [ 2839.103099] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2846.823610] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2862.368455] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2867.488326] LustreError: 75353:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.158@tcp: failed processing log, type 4: rc = -110 [ 2893.217026] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2893.225049] Lustre: Skipped 1 previous similar message [ 2897.614805] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2900.571840] Lustre: 75935: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.588200] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2903.658143] Lustre: 75935:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2910.814927] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 16:18:19 (1784405899) [ 2922.330152] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 2930.543525] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2930.931864] LustreError: 75378:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2931.049116] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3271 to 0x280000401:3297) [ 2934.461879] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2941.586554] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2945.535942] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2947.762502] Lustre: 78601:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2958.923917] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2962.931779] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2964.467108] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2968.188740] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2970.815140] Lustre: 80097:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2974.215287] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2979.421439] Lustre: Failing over lustre-OST0000 [ 2979.521499] Lustre: server umount lustre-OST0000 complete [ 2986.974030] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2987.157465] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2987.160434] Lustre: Skipped 2 previous similar messages [ 2988.772270] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2988.780083] Lustre: Skipped 2 previous similar messages [ 2988.794430] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2988.797764] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2988.799715] Lustre: *** cfs_fail_loc=215, val=0*** [ 2988.804840] Lustre: Skipped 2 previous similar messages [ 2988.819797] Lustre: Skipped 11 previous similar messages [ 2991.946179] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2994.148450] Lustre: *** cfs_fail_loc=215, val=0*** [ 2994.150949] Lustre: Skipped 1 previous similar message [ 2994.741740] 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. [ 2994.752171] Lustre: 81499:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2996.687036] Lustre: Failing over lustre-OST0000 [ 2996.749840] Lustre: server umount lustre-OST0000 complete [ 3003.237856] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3005.362929] Lustre: *** cfs_fail_loc=215, val=0*** [ 3005.364914] Lustre: Skipped 1 previous similar message [ 3008.419453] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3010.531529] Lustre: *** cfs_fail_loc=215, val=0*** [ 3010.542563] Lustre: Skipped 2 previous similar messages [ 3013.611637] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3013.620867] LustreError: Skipped 1 previous similar message [ 3013.621494] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3013.638118] Lustre: Skipped 3 previous similar messages [ 3018.721256] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3018.724141] Lustre: Skipped 3 previous similar messages [ 3021.062651] Lustre: server umount lustre-MDT0000 complete [ 3023.814780] LustreError: 75361:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784406014 with bad export cookie 2760266335285671067 [ 3023.843033] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3023.846948] Lustre: Skipped 1 previous similar message [ 3024.039594] Lustre: server umount lustre-MDT0001 complete [ 3033.421691] Lustre: server umount lustre-OST0000 complete [ 3036.191501] Lustre: server umount lustre-OST0001 complete [ 3043.534328] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 16:20:32 (1784406032) [ 3053.395764] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 3061.459294] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3061.744050] LustreError: 84752:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3061.761056] LustreError: 84752:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 24 previous similar messages [ 3065.027063] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3071.400715] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3075.274119] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3077.508552] Lustre: 85891:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3082.855188] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3088.167491] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 3088.340181] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3094.872949] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3097.071158] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 3099.715782] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3105.437709] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3107.835229] Lustre: 87760:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3132.315779] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 16:22:01 (1784406121) [ 3144.085275] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 16:22:12 (1784406132) [ 3145.187880] Lustre: *** cfs_fail_loc=160f, val=0*** [ 3154.321472] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 16:22:23 (1784406143) [ 3157.097906] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3157.100494] Lustre: Skipped 7 previous similar messages [ 3204.578593] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3204.590523] Lustre: Skipped 3 previous similar messages [ 3206.973876] Lustre: server umount lustre-MDT0000 complete [ 3209.394139] LustreError: 84732:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784406199 with bad export cookie 2760266335285679565 [ 3209.408127] LustreError: 84732:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 8 previous similar messages [ 3209.621420] Lustre: server umount lustre-MDT0001 complete [ 3222.354720] Lustre: server umount lustre-OST0000 complete [ 3235.233327] Lustre: server umount lustre-OST0001 complete [ 3245.836854] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 3253.233720] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3257.103994] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3263.644485] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3267.255882] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3269.820815] Lustre: 93626:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3275.075609] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3280.305403] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3280.430411] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 3287.172389] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3289.329859] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 3289.337120] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 3289.338550] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 3292.000970] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3298.166855] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3301.037816] Lustre: 95498:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3306.032230] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 16:24:54 (1784406294) [ 3307.834087] Lustre: 94673:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 3307.846787] Lustre: 94673:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1377 previous similar messages [ 3307.858959] Lustre: 94673:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3307.862056] Lustre: 94673:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1377 previous similar messages [ 3307.866429] Lustre: 94673:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3307.869734] Lustre: 94673:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1377 previous similar messages [ 3307.880622] Lustre: 94673:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3307.885171] Lustre: 94673:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1377 previous similar messages [ 3307.890151] Lustre: 94673:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3307.894781] Lustre: 94673:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1377 previous similar messages [ 3307.897777] Lustre: 94673:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3307.904985] Lustre: 94673:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1377 previous similar messages [ 3310.414972] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3310.418124] Lustre: Skipped 63 previous similar messages [ 3325.412848] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3325.417545] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3325.435088] Lustre: Skipped 3 previous similar messages [ 3327.438135] Lustre: server umount lustre-MDT0000 complete [ 3330.064092] LustreError: 92467:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784406320 with bad export cookie 2760266335285707964 [ 3330.070791] LustreError: 92467:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3330.337815] Lustre: server umount lustre-MDT0001 complete [ 3342.586404] Lustre: server umount lustre-OST0000 complete [ 3355.418359] Lustre: server umount lustre-OST0001 complete [ 3365.003873] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 3371.897180] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3372.152441] LustreError: 98387:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3372.161213] LustreError: 98387:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 7 previous similar messages [ 3374.787518] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3379.693733] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3382.463855] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3384.303406] Lustre: 99527:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3389.123792] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3390.446419] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3393.370659] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3396.586935] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3399.707344] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3403.729650] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3405.288597] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3405.295183] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3408.944883] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3415.783520] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 16:26:44 (1784406404) [ 3418.601501] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3418.603583] Lustre: Skipped 63 previous similar messages [ 3418.755420] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3426.597126] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 16:26:55 (1784406415) [ 3428.099738] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3428.099738] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3428.142201] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3428.144804] Lustre: Skipped 3 previous similar messages [ 3434.655904] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 16:27:03 (1784406423) [ 3435.781387] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3436.998356] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 16:27:05 (1784406425) [ 3441.727532] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3441.729358] LustreError: 98395:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240002340:0x6c:0x0]/f59 failed: rc = -5 [ 3502.562514] 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 [ 3502.564163] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3502.564227] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3502.576132] Lustre: Skipped 22 previous similar messages [ 3503.734233] Lustre: server umount lustre-MDT0000 complete [ 3509.045250] LustreError: 102598:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784406499 with bad export cookie 2760266335285722699 [ 3509.051333] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3509.053644] LustreError: 102598:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3509.058922] LustreError: Skipped 3 previous similar messages [ 3509.242956] Lustre: server umount lustre-MDT0001 complete [ 3525.557235] Lustre: server umount lustre-OST0000 complete [ 3528.672129] Lustre: 16446:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784406503/real 1784406503] req@ffff9151c3f6d500 x1871082717699328/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1784406519 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3530.928742] Lustre: server umount lustre-OST0001 complete [ 3542.017173] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing unload_modules_local [ 3543.979588] Key type lgssc unregistered [ 3544.177709] LNet: 105223:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3544.182773] LNetError: 105223:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3544.194794] LNet: Removed LNI 192.168.202.158@tcp [ 3544.805158] Key type .llcrypt unregistered [ 3544.810494] Key type ._llcrypt unregistered [ 3560.483396] Key type ._llcrypt registered [ 3560.484842] Key type .llcrypt registered [ 3560.535684] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_hostid [ 3568.955378] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 3569.507555] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3569.589052] alg: No test for adler32 (adler32-zlib) [ 3570.584849] Lustre: Lustre: Build Version: 2.17.54_174_g53e1600 [ 3570.760726] LNet: Added LNI 192.168.202.158@tcp [8/256/0/180] [ 3572.384333] Key type lgssc registered [ 3573.096841] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3600.431781] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 3607.534546] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3607.545841] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3608.663127] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3608.682562] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3608.734334] Lustre: lustre-MDT0000: new disk, initializing [ 3608.772484] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3608.787589] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3611.271423] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3620.091449] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3620.152472] Lustre: 109652: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 [ 3620.179963] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3620.183240] Lustre: Skipped 1 previous similar message [ 3620.232676] Lustre: lustre-MDT0001: new disk, initializing [ 3620.281400] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3620.299514] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3620.305357] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3623.105826] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3626.623531] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3633.157210] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3633.284357] Lustre: lustre-OST0000: new disk, initializing [ 3633.288198] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3633.290662] Lustre: 111588:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3633.360636] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3637.030550] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3637.246593] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3637.250576] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3637.298342] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3646.292304] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3646.389930] Lustre: lustre-OST0001: new disk, initializing [ 3646.392897] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3646.397023] Lustre: 112613:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3646.440721] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3650.661364] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3655.671406] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3655.676764] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3655.702889] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3659.031829] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3663.067157] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3666.934865] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 16:30:55 (1784406655) === [ 3670.936554] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 16:31:00 (1784406660) [ 3671.068131] Lustre: 109657:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3671.073780] Lustre: 109657:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3671.077947] Lustre: 109657:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3671.081833] Lustre: 109657:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3671.086467] Lustre: 109657:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3671.090612] Lustre: 109657:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3671.577250] Lustre: 109659:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3671.585243] Lustre: 109659:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 54 previous similar messages [ 3671.589407] Lustre: 109659:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3671.593277] Lustre: 109659:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 3671.597457] Lustre: 109659:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3671.603355] Lustre: 109659:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 3671.611299] Lustre: 109659:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3671.616786] Lustre: 109659:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 3671.620685] Lustre: 109659:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3671.624212] Lustre: 109659:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 3671.628156] Lustre: 109659:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3671.632227] Lustre: 109659:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 54 previous similar messages [ 3673.009828] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3679.301790] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 16:31:08 (1784406668) [ 3680.030100] Lustre: 109659:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3680.039530] Lustre: 109659:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 254 previous similar messages [ 3680.050937] Lustre: 109659:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3680.056234] Lustre: 109659:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 254 previous similar messages [ 3680.063162] Lustre: 109659:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3680.068348] Lustre: 109659:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 254 previous similar messages [ 3680.078471] Lustre: 109659:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3680.082198] Lustre: 109659:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 254 previous similar messages [ 3680.088186] Lustre: 109659:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3680.092477] Lustre: 109659:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 254 previous similar messages [ 3680.100257] Lustre: 109659:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3680.104695] Lustre: 109659:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 254 previous similar messages [ 3680.881824] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3683.356925] Lustre: 111578:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 3683.364593] Lustre: 111578:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 11 previous similar messages [ 3683.371407] Lustre: 111578:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3683.375478] Lustre: 111578:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3683.381967] Lustre: 111578:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 3683.385950] Lustre: 111578:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3683.390368] Lustre: 111578:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3683.394962] Lustre: 111578:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3683.401176] Lustre: 111578:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3683.408706] Lustre: 111578:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3683.414828] Lustre: 111578:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3683.418945] Lustre: 111578:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3687.168709] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 16:31:16 (1784406676) [ 3687.450315] Lustre: 109657:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3687.453531] Lustre: 109657:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 4 previous similar messages [ 3687.456422] Lustre: 109657:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3687.460649] Lustre: 109657:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3687.464610] Lustre: 109657:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3687.468820] Lustre: 109657:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3687.476333] Lustre: 109657:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3687.481406] Lustre: 109657:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3687.485658] Lustre: 109657:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3687.487971] Lustre: 109657:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3687.493475] Lustre: 109657:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3687.497940] Lustre: 109657:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 3688.905783] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3688.908089] Lustre: Skipped 1 previous similar message [ 3701.439889] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3702.506962] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 16:31:31 (1784406691) [ 3702.872880] Lustre: 109657:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3702.878841] Lustre: 109657:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 18 previous similar messages [ 3702.883247] Lustre: 109657:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3702.888544] Lustre: 109657:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3702.892504] Lustre: 109657:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3702.895597] Lustre: 109657:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3702.899536] Lustre: 109657:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3702.902930] Lustre: 109657:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3702.906551] Lustre: 109657:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3702.909511] Lustre: 109657:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3702.913758] Lustre: 109657:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3702.918558] Lustre: 109657:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3704.355548] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3704.398532] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3705.979857] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3705.982261] Lustre: Skipped 5 previous similar messages [ 3718.533324] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 16:31:47 (1784406707) [ 3718.977492] Lustre: 109657:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 264, rollback = 2 [ 3718.985610] Lustre: 109657:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 27 previous similar messages [ 3718.995616] Lustre: 109657:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3719.000524] Lustre: 109657:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3719.004850] Lustre: 109657:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/264/0 [ 3719.008186] Lustre: 109657:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3719.011914] Lustre: 109657:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3719.016513] Lustre: 109657:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3719.020427] Lustre: 109657:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3719.024917] Lustre: 109657:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3719.030264] Lustre: 109657:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3719.034707] Lustre: 109657:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3720.104991] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3720.106977] Lustre: Skipped 5 previous similar messages [ 3752.931144] 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 [ 3752.940428] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3752.948898] Lustre: Skipped 1 previous similar message [ 3752.963638] Lustre: Skipped 3 previous similar messages [ 3758.053708] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3758.062722] Lustre: Skipped 3 previous similar messages [ 3758.939980] Lustre: server umount lustre-MDT0000 complete [ 3761.532014] LustreError: 109645:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784406752 with bad export cookie 14381934599505481654 [ 3761.534328] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3761.536851] LustreError: 109645:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3761.761501] Lustre: server umount lustre-MDT0001 complete [ 3774.930647] Lustre: server umount lustre-OST0000 complete [ 3787.551468] Lustre: server umount lustre-OST0001 complete [ 3796.791500] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 3801.515265] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3801.724828] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3803.495833] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3807.202975] LustreError: 118317:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3807.212593] LustreError: 118317:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 3807.882416] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3810.281586] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3811.970590] Lustre: 119456:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3815.337858] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3815.506905] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3815.511481] Lustre: Skipped 1 previous similar message [ 3817.569344] LustreError: 119808:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3817.572260] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 3818.525830] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3823.079146] LustreError: 119808:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3823.266938] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3826.477598] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 3826.484782] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3826.554068] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 3827.224526] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3832.258534] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3834.486832] Lustre: 121327:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3843.433641] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 16:33:52 (1784406832) [ 3843.665553] Lustre: 118312:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3843.672725] Lustre: 118312:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 18 previous similar messages [ 3843.677091] Lustre: 118312:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3843.682053] Lustre: 118312:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3843.686971] Lustre: 118312:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3843.691406] Lustre: 118312:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3843.697692] Lustre: 118312:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 3843.702404] Lustre: 118312:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3843.707407] Lustre: 118312:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3843.713527] Lustre: 118312:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3843.720892] Lustre: 118312:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3843.726551] Lustre: 118312:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3845.050962] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3845.058422] Lustre: Skipped 3 previous similar messages [ 3877.858431] 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 [ 3877.859080] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3877.868472] Lustre: Skipped 4 previous similar messages [ 3877.877081] Lustre: Skipped 3 previous similar messages [ 3882.982960] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3882.987995] Lustre: Skipped 3 previous similar messages [ 3883.686655] Lustre: server umount lustre-MDT0000 complete [ 3886.444976] LustreError: 118297:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784406877 with bad export cookie 14381934599505496900 [ 3886.457202] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3886.460166] LustreError: 118297:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3886.643602] Lustre: server umount lustre-MDT0001 complete [ 3898.667461] Lustre: server umount lustre-OST0000 complete [ 3911.240339] Lustre: server umount lustre-OST0001 complete [ 3922.504219] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 3930.077656] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3930.363497] LustreError: 123893:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3930.421785] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3930.425105] Lustre: Skipped 1 previous similar message [ 3934.186867] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3935.713793] LustreError: 123894:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3940.156136] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3943.464601] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3945.478427] Lustre: 125033:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3950.436687] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3954.729935] LustreError: 125387:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3954.750804] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 3954.756591] LustreError: 125387:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 3954.959848] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3960.816608] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3965.079186] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3965.097597] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 3965.097623] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 3965.116794] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 3970.568682] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3972.928645] Lustre: 126904:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3976.459285] Lustre: 123893:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 3976.466692] Lustre: 123893:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3976.471665] Lustre: 123893:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3976.475854] Lustre: 123893:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3976.479377] Lustre: 123893:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 3976.484974] Lustre: 123893:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3976.491225] Lustre: 123893:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 3976.500272] Lustre: 123893:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3976.504542] Lustre: 123893:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 3976.510407] Lustre: 123893:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3976.514272] Lustre: 123893:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3976.518664] Lustre: 123893:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3976.540764] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3976.545943] Lustre: Skipped 1 previous similar message [ 3997.168624] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 16:36:26 (1784406986) [ 3999.367075] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3999.369057] Lustre: Skipped 3 previous similar messages [ 4004.754686] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4017.883308] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 16:36:46 (1784407006) [ 4019.401853] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4019.408058] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4019.414498] Lustre: Skipped 7 previous similar messages [ 4028.433410] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 16:36:57 (1784407017) [ 4042.351338] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 16:37:11 (1784407031) [ 4050.448819] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 16:37:19 (1784407039) [ 4052.432870] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4052.465251] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4052.469399] Lustre: Skipped 3 previous similar messages [ 4056.370460] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.58@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:202 extent [0-4095], client returned csum 0 (type 20), server csum a10080 (type 20) [ 4057.454373] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.58@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 20), server csum a0007f (type 20) [ 4061.794243] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 16:37:31 (1784407051) [ 4063.238038] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4063.240758] Lustre: Skipped 3 previous similar messages [ 4077.992775] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 16:37:47 (1784407067) [ 4081.867152] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 16:37:51 (1784407071) [ 4089.117498] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 16:37:58 (1784407078) [ 4090.533645] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4090.536795] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4090.540725] Lustre: Skipped 1 previous similar message [ 4096.752888] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 16:38:05 (1784407085) [ 4097.800035] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4097.801964] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4104.081100] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 16:38:13 (1784407093) [ 4104.542043] Lustre: 125408:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0001: opcode 2: before 259 < left 292, rollback = 2 [ 4104.551165] Lustre: 125408:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 468 previous similar messages [ 4104.556151] Lustre: 125408:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 4104.560451] Lustre: 125408:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 468 previous similar messages [ 4104.563914] Lustre: 125408:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 2/2/0, xattr_set: 5/292/0 [ 4104.567168] Lustre: 125408:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 468 previous similar messages [ 4104.570015] Lustre: 125408:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 5/84/0, punch: 0/0/0, quota 1/3/0 [ 4104.577543] Lustre: 125408:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 468 previous similar messages [ 4104.581830] Lustre: 125408:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 5/102/1, delete: 0/0/0 [ 4104.584499] Lustre: 125408:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 468 previous similar messages [ 4104.591069] Lustre: 125408:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 4104.594951] Lustre: 125408:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 468 previous similar messages [ 4105.150090] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4113.131366] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4114.238130] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 16:38:23 (1784407103) [ 4117.546216] Lustre: *** cfs_fail_loc=1621, val=127*** [ 4117.548649] Lustre: Skipped 1 previous similar message [ 4119.152456] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4134.210110] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 16:38:43 (1784407123) [ 4135.246793] Lustre: Failing over lustre-MDT0000 [ 4135.514691] Lustre: server umount lustre-MDT0000 complete [ 4138.678421] LustreError: 127770:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.58@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4138.687652] LustreError: 127770:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 4139.492555] 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 [ 4139.500793] Lustre: Skipped 3 previous similar messages [ 4140.319211] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4140.417653] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4140.556205] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4140.558690] Lustre: Skipped 3 previous similar messages [ 4140.583292] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4142.734486] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4143.788838] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4145.634493] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4145.656320] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 4145.686824] LustreError: 123890:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4145.696034] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 4145.696977] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 4151.331193] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 16:39:00 (1784407140) [ 4152.396132] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4152.461454] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4152.463058] Lustre: Skipped 1 previous similar message [ 4157.829423] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 16:39:07 (1784407147) [ 4158.634987] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4163.956206] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 16:39:13 (1784407153) [ 4164.795504] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4170.716958] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 16:39:19 (1784407159) [ 4177.272085] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 16:39:26 (1784407166) [ 4183.750767] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 16:39:33 (1784407173) [ 4184.679382] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4184.682797] Lustre: Skipped 3 previous similar messages [ 4190.208485] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 16:39:39 (1784407179) [ 4193.630952] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4193.634216] Lustre: Skipped 1 previous similar message [ 4202.094659] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 16:39:51 (1784407191) [ 4209.470709] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 16:39:58 (1784407198) [ 4226.795124] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 16:40:16 (1784407216) [ 4227.623121] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4227.625721] Lustre: Skipped 3 previous similar messages [ 4228.199638] LustreError: 123888:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 4231.201416] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 16:40:20 (1784407220) [ 4258.923136] Lustre: Failing over lustre-MDT0000 [ 4259.133091] Lustre: server umount lustre-MDT0000 complete [ 4263.393459] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4263.393958] 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 [ 4263.397681] LustreError: 124624:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4263.405305] Lustre: Skipped 2 previous similar messages [ 4263.411917] LustreError: 124624:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 4 previous similar messages [ 4263.716168] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4263.767115] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4263.867325] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4263.885556] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4265.807183] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4269.024748] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4269.025976] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4269.030359] Lustre: Skipped 3 previous similar messages [ 4269.035579] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4269.051647] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:193) [ 4269.052300] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:321) [ 4273.325592] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 16:41:02 (1784407262) [ 4279.555917] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 16:41:08 (1784407268) [ 4285.915788] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 16:41:15 (1784407275) [ 4286.625128] Lustre: *** cfs_fail_loc=1629, val=0*** [ 4286.626558] Lustre: Skipped 5 previous similar messages [ 4292.117759] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 16:41:21 (1784407281) [ 4294.666033] Lustre: Failing over lustre-MDT0000 [ 4299.745086] 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 [ 4299.745699] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4299.746250] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4299.750558] Lustre: Skipped 4 previous similar messages [ 4299.758752] Lustre: Skipped 3 previous similar messages [ 4299.899630] Lustre: server umount lustre-MDT0000 complete [ 4304.340618] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4304.428511] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4304.579052] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4306.723903] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4307.908381] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4307.912319] Lustre: lustre-MDT0000: Denying connection for new client b7142285-18de-4bd8-a849-e8d7fd2ddc75 (at 192.168.202.58@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 4309.991902] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4309.995220] Lustre: Skipped 3 previous similar messages [ 4310.004226] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 4310.028094] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:225) [ 4310.030733] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:353) [ 4317.169566] Lustre: Failing over lustre-MDT0000 [ 4317.305387] Lustre: server umount lustre-MDT0000 complete [ 4320.226337] 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 [ 4320.226631] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4320.236825] Lustre: Skipped 3 previous similar messages [ 4321.413868] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4321.470761] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4321.584074] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4323.429729] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4323.499995] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4326.887613] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4326.893311] Lustre: Skipped 3 previous similar messages [ 4326.915556] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 4326.940642] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:385) [ 4326.940635] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:227 to 0x2c0000401:257) [ 4330.278984] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 16:41:59 (1784407319) [ 4336.269356] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 16:42:05 (1784407325) [ 4341.785862] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 16:42:11 (1784407331) [ 4372.582119] Lustre: 123888:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0001: opcode 2: before 252 < left 278, rollback = 2 [ 4372.586377] Lustre: 123888:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 549 previous similar messages [ 4372.589690] Lustre: 123888:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4372.593534] Lustre: 123888:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 549 previous similar messages [ 4372.597466] Lustre: 123888:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4372.601557] Lustre: 123888:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 549 previous similar messages [ 4372.605397] Lustre: 123888:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/1, punch: 0/0/0, quota 1/3/2 [ 4372.609270] Lustre: 123888:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 549 previous similar messages [ 4372.613525] Lustre: 123888:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 4372.616914] Lustre: 123888:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 549 previous similar messages [ 4372.621203] Lustre: 123888:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4372.625272] Lustre: 123888:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 549 previous similar messages [ 4375.899769] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 16:42:45 (1784407365) [ 4383.469397] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 16:42:52 (1784407372) [ 4388.155204] LustreError: 148511:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4389.555544] Lustre: Failing over lustre-OST0000 [ 4389.617662] Lustre: server umount lustre-OST0000 complete [ 4390.369697] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4390.373696] 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 [ 4390.382438] LustreError: 126558:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4390.390747] LustreError: 126558:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 6 previous similar messages [ 4391.073070] LustreError: 148511:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 4398.444481] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4398.530562] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4398.533573] Lustre: Skipped 2 previous similar messages [ 4398.537702] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4400.481400] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4400.490145] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4400.490214] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4400.497202] Lustre: Skipped 3 previous similar messages [ 4401.148942] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4404.963072] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 16:43:14 (1784407394) [ 4411.639500] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 4420.641538] Lustre: 151309:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4431.636448] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4437.486118] LustreError: 152557:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4437.491102] LustreError: 152557:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 4438.530239] Lustre: Failing over lustre-MDT0001 [ 4439.521593] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4439.521604] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 4439.525441] Lustre: Skipped 1 previous similar message [ 4439.526025] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4439.527541] LustreError: Skipped 1 previous similar message [ 4440.504130] LustreError: 152556:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 4440.508598] LustreError: 152556:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4440.596763] Lustre: server umount lustre-MDT0001 complete [ 4441.760081] LustreError: 152556:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 4448.932271] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4449.082382] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4450.625177] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4454.105150] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 16:44:03 (1784407443) [ 4454.369724] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4454.371157] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4454.376280] Lustre: Skipped 1 previous similar message [ 4454.383633] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4454.402874] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 4454.402880] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 4459.527687] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 4466.568574] Lustre: 155271:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4466.572311] Lustre: 155271:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 4475.591958] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4484.446041] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 16:44:33 (1784407473) [ 4485.110466] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 4485.861273] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 16:44:35 (1784407475) [ 4488.357988] Lustre: *** cfs_fail_loc=1631, val=0*** [ 4495.329202] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4495.329279] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4495.333707] Lustre: Skipped 5 previous similar messages [ 4500.122932] Lustre: server umount lustre-MDT0000 complete [ 4501.436131] LustreError: 143567:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784407492 with bad export cookie 14381934599505569644 [ 4501.437657] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4501.440320] LustreError: 143567:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4501.551725] Lustre: server umount lustre-MDT0001 complete [ 4512.776549] Lustre: server umount lustre-OST0000 complete [ 4524.313459] Lustre: server umount lustre-OST0001 complete [ 4530.063078] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 4533.746671] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4533.892804] LustreError: 159150:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4533.901124] LustreError: 159150:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 10 previous similar messages [ 4535.459372] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4539.016028] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4540.825387] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4542.060383] Lustre: 160290:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4542.064688] Lustre: 160290:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 4544.696091] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4547.099318] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4548.901231] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 4550.664809] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4552.965690] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4555.748232] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 4558.822276] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 4558.822277] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 4561.611257] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4566.812610] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 16:45:56 (1784407556) [ 4567.500155] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 4568.291674] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 16:45:57 (1784407557) [ 4568.931716] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 4569.680699] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 16:45:59 (1784407559) [ 4570.327049] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 4571.032976] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 16:46:00 (1784407560) [ 4575.147941] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 16:46:04 (1784407564) [ 4580.398644] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 16:46:09 (1784407569) [ 4585.958899] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 16:46:15 (1784407575) [ 4591.573981] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 16:46:21 (1784407581) [ 4598.424486] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 16:46:27 (1784407587) [ 4630.432496] Lustre: *** cfs_fail_loc=1632, val=0*** [ 4635.869709] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 16:47:05 (1784407625) [ 4637.046392] Lustre: Failing over lustre-MDT0001 [ 4637.145156] Lustre: server umount lustre-MDT0001 complete [ 4640.315566] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4640.394566] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4640.401254] Lustre: Skipped 6 previous similar messages [ 4640.435946] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4640.436082] Lustre: lustre-MDT0001: Aborting client recovery [ 4640.441322] LustreError: 165935:0:(ldlm_lib.c:3003:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 4640.442225] LustreError: 165957:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osd: get update log duration 1, retries 0, failed: rc = -108 [ 4640.445248] Lustre: 165959:0:(ldlm_lib.c:2403:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4640.455050] Lustre: 165959:0:(genops.c:1601:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client fa3647ea-e23b-48e5-8f6e-9c5339b82027@ [ 4640.459530] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 4640.462704] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 4640.468713] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 4640.491348] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:161) [ 4640.495024] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 4642.012890] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4643.610734] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 4645.250220] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 4645.858848] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4645.861593] Lustre: Skipped 2 previous similar messages [ 4645.864703] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 4646.406908] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 1 sec [ 4648.886127] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 16:47:18 (1784407638) [ 4651.419835] Lustre: *** cfs_fail_loc=1600, val=3*** [ 4653.085113] Lustre: Failing over lustre-MDT0000 [ 4653.363958] Lustre: server umount lustre-MDT0000 complete [ 4655.075588] LustreError: 159892:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784407645 with bad export cookie 14381934599505642192 [ 4655.080778] LustreError: 159892:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 9 previous similar messages [ 4657.026856] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4657.090155] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4657.192430] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4657.194907] Lustre: Skipped 6 previous similar messages [ 4658.824725] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4660.390297] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4662.252336] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 4662.270915] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 4662.270922] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 4662.473321] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 16:47:31 (1784407651) [ 4675.571416] Lustre: Failing over lustre-OST0000 [ 4675.631986] Lustre: server umount lustre-OST0000 complete [ 4676.576571] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4677.981761] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 4682.248052] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4682.315261] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4682.317867] Lustre: Skipped 3 previous similar messages [ 4684.150784] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4684.153830] Lustre: Skipped 6 previous similar messages [ 4684.425876] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4686.590208] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 4686.666560] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 4688.085538] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 4688.163924] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 4690.203532] Lustre: DEBUG MARKER: oleg258-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff92f6c4996800.ost_server_uuid 50 [ 4690.781443] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff92f6c4996800.ost_server_uuid in FULL state after 0 sec [ 4707.557988] Lustre: server umount lustre-MDT0000 complete [ 4710.638799] LustreError: 159132:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784407701 with bad export cookie 14381934599505652314 [ 4710.646695] LustreError: 159132:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4710.757451] Lustre: server umount lustre-MDT0001 complete [ 4724.232699] Lustre: server umount lustre-OST0000 complete [ 4736.534048] Lustre: server umount lustre-OST0001 complete [ 4742.480300] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing unload_modules_local [ 4743.676540] Key type lgssc unregistered [ 4743.823636] LNet: 175053:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 4743.826811] LNetError: 175053:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 4743.835563] LNet: Removed LNI 192.168.202.158@tcp [ 4744.211152] Key type .llcrypt unregistered [ 4744.212254] Key type ._llcrypt unregistered [ 4752.399424] Key type ._llcrypt registered [ 4752.400771] Key type .llcrypt registered [ 4752.443813] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_hostid [ 4759.125087] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 4759.637412] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 4759.644832] alg: No test for adler32 (adler32-zlib) [ 4760.508151] Lustre: Lustre: Build Version: 2.17.54_174_g53e1600 [ 4760.603386] LNet: Added LNI 192.168.202.158@tcp [8/256/0/180] [ 4762.184185] Key type lgssc registered [ 4762.602470] Lustre: Echo OBD driver; http://www.lustre.org/ [ 4782.028809] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing load_modules_local [ 4786.652030] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 4786.662192] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4787.755065] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4787.767689] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4787.802111] Lustre: lustre-MDT0000: new disk, initializing [ 4787.825818] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4787.834691] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4789.287957] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4794.977365] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4795.016795] Lustre: 179485: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 [ 4795.031670] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4795.034593] Lustre: Skipped 1 previous similar message [ 4795.079324] Lustre: lustre-MDT0001: new disk, initializing [ 4795.112658] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4795.125794] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4795.130697] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4796.709036] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4799.299136] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4802.679392] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4802.760287] Lustre: lustre-OST0000: new disk, initializing [ 4802.763306] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4802.767451] Lustre: 181426:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4802.791961] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4804.929671] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4810.479935] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4810.525989] Lustre: lustre-OST0001: new disk, initializing [ 4810.528585] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4810.531432] Lustre: 182439:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4810.558475] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 4811.075501] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4811.079084] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4811.084325] Lustre: Skipped 1 previous similar message [ 4811.111422] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4811.119629] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4812.656420] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4818.302202] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4821.077723] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4823.118180] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 16:50:12 (1784407812) === [ 4823.646632] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 4477 sec ========= 16:50:13 (1784407813) [ 4824.198456] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 16:50:13 (1784407813) === [ 4825.303551] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 16:50:14 (1784407814) === [ 4826.395813] Lustre: server umount lustre-MDT0000 complete [ 4826.592927] 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 [ 4826.596463] Lustre: Skipped 1 previous similar message [ 4829.406680] LustreError: 179476:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1784407819 with bad export cookie 5047198671733082046 [ 4829.408016] LustreError: MGC192.168.202.158@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4829.410644] LustreError: 179476:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4831.526557] Lustre: server umount lustre-MDT0001 complete [ 4844.866992] Lustre: server umount lustre-OST0000 complete [ 4858.337657] Lustre: server umount lustre-OST0001 complete [ 4869.303572] Lustre: DEBUG MARKER: oleg258-server.virtnet: executing unload_modules_local [ 4871.297832] Key type lgssc unregistered [ 4871.514734] LNet: 185915:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 4871.518415] LNetError: 185915:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 4872.549837] LNet: Removed LNI 192.168.202.158@tcp [ 4873.097160] Key type .llcrypt unregistered [ 4873.102080] Key type ._llcrypt unregistered