[ 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 479211838 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2895240K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001012] APIC: Switch to symmetric I/O mode setup [ 0.002319] x2apic enabled [ 0.003008] Switched APIC routing to physical x2apic. [ 0.004016] kvm-guest: setup PV IPIs [ 0.006978] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007019] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008010] pid_max: default: 32768 minimum: 301 [ 0.010034] LSM: Security Framework initializing [ 0.011056] Yama: becoming mindful. [ 0.012041] SELinux: Initializing. [ 0.013084] *** VALIDATE selinux *** [ 0.021793] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026307] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.027163] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028122] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030048] *** VALIDATE tmpfs *** [ 0.031469] *** VALIDATE proc *** [ 0.032234] *** VALIDATE cgroup *** [ 0.033012] *** VALIDATE cgroup2 *** [ 0.035174] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.036125] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.037010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.038029] Spectre V2 : User space: Vulnerable [ 0.039010] Speculative Store Bypass: Vulnerable [ 0.042518] debug: unmapping init [mem 0xffffffffa7e59000-0xffffffffa7e60fff] [ 0.044185] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.045706] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.046025] ... version: 2 [ 0.047013] ... bit width: 48 [ 0.048014] ... generic registers: 4 [ 0.049014] ... value mask: 0000ffffffffffff [ 0.050011] ... max period: 00007fffffffffff [ 0.051011] ... fixed-purpose events: 3 [ 0.052013] ... event mask: 000000070000000f [ 0.053305] rcu: Hierarchical SRCU implementation. [ 0.055455] smp: Bringing up secondary CPUs ... [ 0.056628] x86: Booting SMP configuration: [ 0.057023] .... node #0, CPUs: #1 #2 #3 [ 0.060270] smp: Brought up 1 node, 4 CPUs [ 0.062011] smpboot: Max logical packages: 1 [ 0.063012] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.182787] node 0 deferred pages initialised in 117ms [ 0.188012] devtmpfs: initialized [ 0.189240] x86/mm: Memory block size: 128MB [ 0.191455] gcov: version magic: 0x41383552 [ 0.195281] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.196075] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.197252] pinctrl core: initialized pinctrl subsystem [ 0.198182] [ 0.198977] ************************************************************* [ 0.199015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.200009] ** ** [ 0.201010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.202012] ** ** [ 0.203012] ** This means that this kernel is built to expose internal ** [ 0.204013] ** IOMMU data structures, which may compromise security on ** [ 0.205014] ** your system. ** [ 0.206010] ** ** [ 0.207015] ** If you see this message and you are not debugging the ** [ 0.208012] ** kernel, report this immediately to your vendor! ** [ 0.209013] ** ** [ 0.210014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.211011] ************************************************************* [ 0.212702] NET: Registered protocol family 16 [ 0.214485] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.219105] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.223093] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.227582] cpuidle: using governor menu [ 0.229863] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.233464] PCI: Using configuration type 1 for base access [ 0.235119] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.245076] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.248056] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.252042] cryptd: max_cpu_qlen set to 1000 [ 0.255233] ACPI: Added _OSI(Module Device) [ 0.257030] ACPI: Added _OSI(Processor Device) [ 0.259022] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.261015] ACPI: Added _OSI(Processor Aggregator Device) [ 0.265253] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.270334] ACPI: Interpreter enabled [ 0.271031] ACPI: PM: (supports S0 S3 S4 S5) [ 0.273012] ACPI: Using IOAPIC for interrupt routing [ 0.274120] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.277381] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.286951] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.290041] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.292019] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.296082] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.301679] acpiphp: Slot [2] registered [ 0.303082] acpiphp: Slot [5] registered [ 0.304119] acpiphp: Slot [6] registered [ 0.306145] acpiphp: Slot [7] registered [ 0.308106] acpiphp: Slot [8] registered [ 0.309160] acpiphp: Slot [9] registered [ 0.311138] acpiphp: Slot [10] registered [ 0.312077] acpiphp: Slot [3] registered [ 0.313061] acpiphp: Slot [4] registered [ 0.315092] acpiphp: Slot [11] registered [ 0.316095] acpiphp: Slot [12] registered [ 0.317061] acpiphp: Slot [13] registered [ 0.318082] acpiphp: Slot [14] registered [ 0.319074] acpiphp: Slot [15] registered [ 0.321070] acpiphp: Slot [16] registered [ 0.322082] acpiphp: Slot [17] registered [ 0.324123] acpiphp: Slot [18] registered [ 0.325120] acpiphp: Slot [19] registered [ 0.326059] acpiphp: Slot [20] registered [ 0.327093] acpiphp: Slot [21] registered [ 0.329097] acpiphp: Slot [22] registered [ 0.330081] acpiphp: Slot [23] registered [ 0.332155] acpiphp: Slot [24] registered [ 0.333073] acpiphp: Slot [25] registered [ 0.334085] acpiphp: Slot [26] registered [ 0.335063] acpiphp: Slot [27] registered [ 0.336089] acpiphp: Slot [28] registered [ 0.338115] acpiphp: Slot [29] registered [ 0.340107] acpiphp: Slot [30] registered [ 0.341090] acpiphp: Slot [31] registered [ 0.343059] PCI host bridge to bus 0000:00 [ 0.345025] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.346014] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.349022] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.351017] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.353022] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.356020] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.357165] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.359975] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.363271] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.372015] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.378654] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.381020] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.383014] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.386018] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.389505] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.392779] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.396040] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.399889] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.406016] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.418021] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.424018] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.429825] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.439014] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.446015] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.464018] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.474777] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.480014] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.486011] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.499012] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.508391] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.514014] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.519012] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.533886] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.542000] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.556018] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.568017] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.585015] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.593468] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.598017] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.605018] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.620025] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.633986] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.642013] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.647017] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.665023] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.681250] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.683406] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.687394] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.690404] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.692204] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.695157] iommu: Default domain type: Passthrough [ 0.698541] SCSI subsystem initialized [ 0.701137] ACPI: bus type USB registered [ 0.703137] usbcore: registered new interface driver usbfs [ 0.707091] usbcore: registered new interface driver hub [ 0.710090] usbcore: registered new device driver usb [ 0.713187] pps_core: LinuxPPS API ver. 1 registered [ 0.716014] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.721063] PTP clock support registered [ 0.724202] EDAC MC: Ver: 3.0.0 [ 0.727187] PCI: Using ACPI for IRQ routing [ 0.731392] NetLabel: Initializing [ 0.733024] NetLabel: domain hash size = 128 [ 0.734019] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.737115] NetLabel: unlabeled traffic allowed by default [ 0.739122] vgaarb: loaded [ 0.741259] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.743016] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.750362] clocksource: Switched to clocksource kvm-clock [ 0.856704] VFS: Disk quotas dquot_6.6.0 [ 0.858879] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.862769] *** VALIDATE ramfs *** [ 0.864465] *** VALIDATE hugetlbfs *** [ 0.866722] pnp: PnP ACPI init [ 0.870060] pnp: PnP ACPI: found 6 devices [ 0.889085] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.893200] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.896047] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.898639] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.901558] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.904608] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.908173] NET: Registered protocol family 2 [ 0.911270] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.917373] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.921368] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.927454] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.932404] TCP: Hash tables configured (established 65536 bind 65536) [ 0.935604] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.940133] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.943600] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.947220] NET: Registered protocol family 1 [ 0.950071] RPC: Registered named UNIX socket transport module. [ 0.952645] RPC: Registered udp transport module. [ 0.954549] RPC: Registered tcp transport module. [ 0.956655] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.959497] NET: Registered protocol family 44 [ 0.961427] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.964031] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.966469] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.968897] PCI: CLS 0 bytes, default 64 [ 0.971434] Unpacking initramfs... [ 2.408814] debug: unmapping init [mem 0xffff9f15fcc54000-0xffff9f15fffbffff] [ 2.412717] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.415268] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.418204] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.899146] Initialise system trusted keyrings [ 2.900913] Key type blacklist registered [ 2.902978] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.911573] zbud: loaded [ 2.914482] *** VALIDATE nfs *** [ 2.915886] *** VALIDATE nfs4 *** [ 2.917456] pstore: using deflate compression [ 2.920813] Platform Keyring initialized [ 3.027512] NET: Registered protocol family 38 [ 3.029453] Key type asymmetric registered [ 3.030967] Asymmetric key parser 'x509' registered [ 3.033121] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.037372] io scheduler mq-deadline registered [ 3.039697] io scheduler kyber registered [ 3.041839] io scheduler bfq registered [ 3.043935] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.046700] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.049228] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.051636] ACPI: Power Button [PWRF] [ 3.058868] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.065526] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.081636] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.091785] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.112678] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.143417] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.174222] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.179293] Non-volatile memory driver v1.3 [ 3.181182] Linux agpgart interface v0.103 [ 3.209449] virtio_blk virtio1: [vda] 146048 512-byte logical blocks (74.8 MB/71.3 MiB) [ 3.211720] vda: detected capacity change from 0 to 74776576 [ 3.224572] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.227302] vdb: detected capacity change from 0 to 1073741824 [ 3.241484] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.244400] vdc: detected capacity change from 0 to 2621440000 [ 3.261534] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.264298] vdd: detected capacity change from 0 to 2621440000 [ 3.280618] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.285155] vde: detected capacity change from 0 to 4294967296 [ 3.305168] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.308266] vdf: detected capacity change from 0 to 4294967296 [ 3.316075] libphy: Fixed MDIO Bus: probed [ 3.321915] usbcore: registered new interface driver usbserial_generic [ 3.324339] usbserial: USB Serial support registered for generic [ 3.326537] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.331051] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.332887] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.335347] mousedev: PS/2 mouse device common for all mice [ 3.338162] rtc_cmos 00:05: RTC can wake from S4 [ 3.341094] rtc_cmos 00:05: registered as rtc0 [ 3.341346] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.343572] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.349985] intel_pstate: CPU model not supported [ 3.353596] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.358030] hid: raw HID events driver (C) Jiri Kosina [ 3.358433] usbcore: registered new interface driver usbhid [ 3.364183] usbhid: USB HID core driver [ 3.364351] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.366067] drop_monitor: Initializing network drop monitor service [ 3.371666] Initializing XFRM netlink socket [ 3.373643] NET: Registered protocol family 10 [ 3.376423] Segment Routing with IPv6 [ 3.377543] NET: Registered protocol family 17 [ 3.379232] mpls_gso: MPLS GSO support [ 3.384713] RAS: Correctable Errors collector initialized. [ 3.387588] AVX version of gcm_enc/dec engaged. [ 3.389531] AES CTR mode by8 optimization enabled [ 3.467191] sched_clock: Marking stable (3467156632, 0)->(4429914262, -962757630) [ 3.471628] registered taskstats version 1 [ 3.473683] Loading compiled-in X.509 certificates [ 3.476117] zswap: loaded using pool lzo/zbud [ 3.502102] Key type big_key registered [ 3.515099] Key type encrypted registered [ 3.516774] ima: No TPM chip found, activating TPM-bypass! [ 3.518534] ima: Allocated hash algorithm: sha1 [ 3.519621] ima: No architecture policies found [ 3.521508] evm: Initialising EVM extended attributes: [ 3.523824] evm: security.selinux [ 3.525469] evm: security.ima [ 3.526762] evm: security.capability [ 3.528417] evm: HMAC attrs: 0x1 [ 3.531276] rtc_cmos 00:05: setting system clock to 2026-08-20 01:40:35 UTC (1787190035) [ 3.538938] debug: unmapping init [mem 0xffffffffa8e03000-0xffffffffa8ffffff] [ 3.542544] debug: unmapping init [mem 0xffffffffa7b82000-0xffffffffa7e58fff] [ 3.551209] Write protecting the kernel read-only data: 28672k [ 3.554729] debug: unmapping init [mem 0xffffffffa6203000-0xffffffffa63fffff] [ 3.557871] debug: unmapping init [mem 0xffffffffa6b14000-0xffffffffa6bfffff] [ 3.593950] 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.603630] systemd[1]: Detected virtualization kvm. [ 3.605935] systemd[1]: Detected architecture x86-64. [ 3.607877] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.637761] systemd[1]: No hostname configured. [ 3.640649] systemd[1]: Set hostname to . [ 3.643371] random: systemd: uninitialized urandom read (16 bytes read) [ 3.646390] systemd[1]: Initializing machine ID from random generator. [ 3.703262] random: ln: uninitialized urandom read (6 bytes read) [ 3.786215] random: systemd: uninitialized urandom read (16 bytes read) [ 3.789373] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 3.795694] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 3.802785] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Slices. [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Timers. Starting Journal Service... [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... Starting Setup Virtual Console... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... [ OK ] Started Setup Virtual Console. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. Starting dracut cmdline hook... [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.525146] device-mapper: uevent: version 1.0.3 [ 4.527765] 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. [ 5.168568] random: fast init done [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.338837] virtio_net virtio0 ens2: renamed from eth0 [ 5.389086] scsi host0: ata_piix [ 5.408590] scsi host1: ata_piix [ 5.410329] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.413926] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.959547] dracut-initqueue[587]: RTNETLINK answers: File exists [ 10.034799] random: crng init done [ 10.038124] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 10.678706] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped Apply Kernel Variables. Stopping udev Kernel Device Manager... [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.922604] printk: systemd: 25 output lines suppressed due to ratelimiting [ 12.206187] SELinux: Disabled at runtime. [ 12.269418] 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) [ 12.280482] systemd[1]: Detected virtualization kvm. [ 12.282713] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.833616] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.837583] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.843513] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.847819] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.851514] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.863270] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.871931] systemd[1]: proc-sys-fs-binfmt_misc.automount: Refusing to start, unit to trigger not loaded. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Starting Create list of required st…ce nodes for the current kernel... Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice User and Session Slice. [ OK ] Reached target RPC Port Mapper. [ 12.923929] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Mounting POSIX Message Queue File System... [ OK ] Reached target rpc_pipefs.target. Mounting Huge Pages File System... Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-serial\x2dgetty.slice. Starting Apply Kernel Variables... [ OK ] Started Dispatch Password Requests to Console Directory Watch. Mounting Kernel Debug File System... [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-getty.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. [ OK ] Reached target Slices. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt.[ 13.385207] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.755376] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.817820] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 14.006885] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 14.017199] EDAC sbridge: Ver: 1.1.2 [ 15.735714] Key type dns_resolver registered [ 16.048092] NFS: Registering the id_resolver key type [ 16.050740] Key type id_resolver registered [ 16.052569] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Login Service. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg353-server login: [ 56.951274] libcfs: loading out-of-tree module taints kernel. [ 57.029400] Key type ._llcrypt registered [ 57.034412] Key type .llcrypt registered [ 57.183517] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_hostid [ 75.841725] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 77.556260] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 77.576200] alg: No test for adler32 (adler32-zlib) [ 79.109117] Lustre: Lustre: Build Version: 2.17.57_44_gafaaa93 [ 80.062174] LNet: Added LNI 192.168.203.153@tcp [8/256/0/180] [ 81.804244] Key type lgssc registered [ 82.835405] hrtimer: interrupt took 5393060 ns [ 83.874497] Lustre: Echo OBD driver; http://www.lustre.org/ [ 102.048858] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 148.220944] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 162.022481] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 162.091774] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 163.394265] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 163.420538] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 163.425182] Lustre: lustre-MDT0000: new disk, initializing [ 163.538659] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 163.560831] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 168.032295] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 180.506544] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 180.569616] Lustre: 6529: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 [ 180.599039] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 180.602616] Lustre: Skipped 1 previous similar message [ 180.606452] Lustre: lustre-MDT0001: new disk, initializing [ 180.645462] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 180.681985] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 180.695328] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 184.117693] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 188.095257] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 198.569474] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 198.861202] Lustre: lustre-OST0000: new disk, initializing [ 198.865245] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 198.870314] Lustre: 8467:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 198.910168] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 202.342351] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 202.357160] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 202.482641] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 205.880349] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 219.743181] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 219.893312] Lustre: lustre-OST0001: new disk, initializing [ 219.902161] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 219.911252] Lustre: 9542:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 219.946769] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 226.863575] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 226.885287] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 226.934391] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 227.007233] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 238.770506] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 245.478318] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 251.522197] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing check_logdir /tmp/testlogs/ [ 257.418934] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing yml_node [ 261.430139] Lustre: DEBUG MARKER: Client: 2.17.57.44 [ 264.180903] Lustre: DEBUG MARKER: MDS: 2.17.57.44 [ 266.771760] Lustre: DEBUG MARKER: OSS: 2.17.57.44 [ 268.576970] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Wed Aug 19 21:44:59 EDT 2026 [ 285.690075] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 299.192584] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 308.710509] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 308.722590] 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 [ 308.751687] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 312.776721] Lustre: server umount lustre-MDT0000 complete [ 319.462538] LustreError: 10117:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 319.504108] LustreError: 10117:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 8 previous similar messages [ 321.160381] LustreError: 6520:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787190353 with bad export cookie 4911549308000700246 [ 321.161898] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 321.177209] LustreError: 6520:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 321.375648] Lustre: server umount lustre-MDT0001 complete [ 338.315557] Lustre: server umount lustre-OST0000 complete [ 340.960115] Lustre: 3645:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787190356/real 1787190356] req@ffff9f1652352a00 x1874004658981376/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787190372 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 340.999865] 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 [ 341.025605] Lustre: Skipped 3 previous similar messages [ 342.496238] Lustre: 3642:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787190358/real 1787190358] req@ffff9f1652350a80 x1874004658981632/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787190374 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 345.576396] Lustre: 3644:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787190361/real 1787190361] req@ffff9f1652350000 x1874004658981888/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787190377 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 346.732329] Lustre: server umount lustre-OST0001 complete [ 361.886722] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing unload_modules_local [ 365.059474] Key type lgssc unregistered [ 365.455801] LNet: 14817:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 365.483130] LNetError: 14817:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 365.512347] LNet: Removed LNI 192.168.203.153@tcp [ 366.679265] Key type .llcrypt unregistered [ 366.681613] Key type ._llcrypt unregistered [ 390.555628] Key type ._llcrypt registered [ 390.557404] Key type .llcrypt registered [ 390.651850] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_hostid [ 405.762437] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 407.693816] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 407.703223] alg: No test for adler32 (adler32-zlib) [ 408.925568] Lustre: Lustre: Build Version: 2.17.57_44_gafaaa93 [ 409.336691] LNet: Added LNI 192.168.203.153@tcp [8/256/0/180] [ 411.136239] Key type lgssc registered [ 412.445696] Lustre: Echo OBD driver; http://www.lustre.org/ [ 459.722550] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 472.834655] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 472.867495] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 474.180555] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 474.222636] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 474.229843] Lustre: lustre-MDT0000: new disk, initializing [ 474.289809] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 474.306940] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 478.837371] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 492.492146] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 492.648625] Lustre: 19269: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 [ 492.702772] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 492.710032] Lustre: Skipped 1 previous similar message [ 492.719334] Lustre: lustre-MDT0001: new disk, initializing [ 492.774228] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 492.799064] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 492.812249] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 497.454668] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 502.228608] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 511.413403] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 511.729937] Lustre: lustre-OST0000: new disk, initializing [ 511.736798] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 511.753963] Lustre: 21206:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 511.814841] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 515.296092] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 515.311696] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 515.396819] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 517.345182] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 531.684158] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 531.840583] Lustre: lustre-OST0001: new disk, initializing [ 531.846428] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 531.856365] Lustre: 22229:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 531.928728] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 537.630939] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 537.641691] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 537.722693] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 538.560527] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 550.233668] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 557.732937] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 566.205227] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 21:49:57 (1787190597) === [ 568.580177] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 21:49:59 (1787190599) [ 568.760979] Lustre: 22759:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 568.771976] Lustre: 22759:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 568.806452] Lustre: 22759:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 568.820696] Lustre: 22759:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 568.832877] Lustre: 22759:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 568.860673] Lustre: 22759:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 569.343871] Lustre: 19276:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 569.355423] Lustre: 19276:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 14 previous similar messages [ 569.362280] Lustre: 19276:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 569.369384] Lustre: 19276:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 569.375378] Lustre: 19276:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 569.388074] Lustre: 19276:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 569.397896] Lustre: 19276:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 569.412388] Lustre: 19276:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 569.417934] Lustre: 19276:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 569.431684] Lustre: 19276:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 569.437713] Lustre: 19276:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 569.447933] Lustre: 19276:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 570.343234] Lustre: 19278:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 570.347827] Lustre: 19278:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 68 previous similar messages [ 570.381659] Lustre: 22759:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 570.386775] Lustre: 22759:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 71 previous similar messages [ 570.392080] Lustre: 22759:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 570.401143] Lustre: 22759:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 71 previous similar messages [ 570.406869] Lustre: 22759:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 570.412778] Lustre: 22759:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 71 previous similar messages [ 570.417608] Lustre: 22759:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 570.423333] Lustre: 22759:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 71 previous similar messages [ 570.460590] Lustre: 19278:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 570.466609] Lustre: 19278:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 74 previous similar messages [ 572.387231] Lustre: 19277:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 572.396920] Lustre: 19277:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 128 previous similar messages [ 572.406178] Lustre: 19277:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 572.413686] Lustre: 19277:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 572.420169] Lustre: 19277:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 572.437257] Lustre: 19277:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 572.446804] Lustre: 19277:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 572.458125] Lustre: 19277:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 572.466198] Lustre: 19277:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 572.475984] Lustre: 19277:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 572.484782] Lustre: 19277:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 572.489838] Lustre: 19277:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 122 previous similar messages [ 574.789114] Lustre: *** cfs_fail_loc=1600, val=3*** [ 578.880279] Lustre: *** cfs_fail_loc=1600, val=3*** [ 578.925039] Lustre: 23440:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 578.931805] Lustre: 21196:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 578.941522] Lustre: 23440:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 63 previous similar messages [ 578.941545] Lustre: 23440:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 578.941548] Lustre: 23440:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 578.941554] Lustre: 23440:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 578.941557] Lustre: 23440:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 578.941562] Lustre: 23440:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 578.941564] Lustre: 23440:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 578.941569] Lustre: 23440:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 578.941572] Lustre: 23440:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 579.044189] Lustre: 21196:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 69 previous similar messages [ 593.161910] Lustre: server umount lustre-MDT0000 complete [ 593.892896] 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 [ 593.916698] Lustre: Skipped 3 previous similar messages [ 596.604706] LustreError: 19263:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787190628 with bad export cookie 13550285211734910057 [ 596.606667] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 596.620773] LustreError: 19263:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 596.782279] Lustre: server umount lustre-MDT0001 complete [ 610.839546] Lustre: server umount lustre-OST0000 complete [ 624.679370] Lustre: server umount lustre-OST0001 complete [ 633.234486] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 21:51:04 (1787190664) [ 646.729502] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 656.661179] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 656.962570] LustreError: 26285:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 656.980661] LustreError: 26285:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 5 previous similar messages [ 657.054927] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 661.451352] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 662.499404] LustreError: 26286:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 662.517945] LustreError: 26286:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 666.594230] LustreError: 26285:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 670.353581] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 670.558147] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 675.650849] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 678.843406] Lustre: 27428:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 685.508877] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 692.129953] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 696.039137] LustreError: 27781:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 701.162533] LustreError: 27784:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 701.174826] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 701.182300] LustreError: 27784:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 702.505067] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 702.926951] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 702.935552] Lustre: Skipped 1 previous similar message [ 708.071759] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:40 to 0x2c0000401:65) [ 709.889358] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 717.824978] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 722.356558] Lustre: 29297:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 723.857436] Lustre: 26280:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 723.864255] Lustre: 26280:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 69 previous similar messages [ 723.869436] Lustre: 26280:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 723.875426] Lustre: 26280:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 63 previous similar messages [ 723.886218] Lustre: 26280:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 723.895196] Lustre: 26280:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 70 previous similar messages [ 723.901222] Lustre: 26280:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 723.912870] Lustre: 26280:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 70 previous similar messages [ 723.921263] Lustre: 26280:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 723.937089] Lustre: 26280:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 70 previous similar messages [ 723.947178] Lustre: 26280:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 723.955482] Lustre: 26280:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 70 previous similar messages [ 729.682820] Lustre: *** cfs_fail_loc=1501, val=0*** [ 738.512244] Lustre: Failing over lustre-MDT0000 [ 738.607151] Lustre: server umount lustre-MDT0000 complete [ 738.789384] 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 [ 738.807629] LustreError: 26281:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 738.832702] LustreError: 26281:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 749.145518] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 749.404840] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 749.581202] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 749.643564] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 754.659486] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 754.681361] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 754.717683] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 754.734279] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 754.736338] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 754.858770] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 757.997227] Lustre: *** cfs_fail_loc=1505, val=0*** [ 765.536589] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 21:53:16 (1787190796) [ 766.627427] Lustre: 26282:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 766.633235] Lustre: 26282:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 322 previous similar messages [ 766.638072] Lustre: 26282:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 766.643396] Lustre: 26282:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 766.648061] Lustre: 26282:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 766.652691] Lustre: 26282:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 766.656941] Lustre: 26282:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 766.660459] Lustre: 26282:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 766.664844] Lustre: 26282:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 766.669846] Lustre: 26282:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 766.674445] Lustre: 26282:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 766.678745] Lustre: 26282:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 771.764410] Lustre: *** cfs_fail_loc=1502, val=0*** [ 781.282108] Lustre: Failing over lustre-MDT0000 [ 781.413445] Lustre: server umount lustre-MDT0000 complete [ 785.380149] 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 [ 785.382361] LustreError: 26280:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 785.382527] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 785.406607] Lustre: Skipped 6 previous similar messages [ 785.480920] LustreError: 26280:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 11 previous similar messages [ 793.117189] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 793.242924] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 793.470183] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 798.288641] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 798.715607] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 798.726812] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 798.757389] Lustre: Skipped 3 previous similar messages [ 798.775406] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 798.788014] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 798.796169] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 802.242529] Lustre: *** cfs_fail_loc=1505, val=0*** [ 811.418891] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 21:54:02 (1787190842) [ 812.967433] Lustre: 26282:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 812.975295] Lustre: 26282:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 322 previous similar messages [ 812.980307] Lustre: 26282:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 812.985064] Lustre: 26282:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 812.990346] Lustre: 26282:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 812.995541] Lustre: 26282:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 813.008580] Lustre: 26282:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 813.027655] Lustre: 26282:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 813.040787] Lustre: 26282:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 813.054682] Lustre: 26282:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 813.072288] Lustre: 26282:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 813.090378] Lustre: 26282:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 819.624319] Lustre: *** cfs_fail_loc=1504, val=0*** [ 819.630574] Lustre: *** cfs_fail_loc=1504, val=0*** [ 819.632761] Lustre: Skipped 1 previous similar message [ 827.844507] Lustre: Failing over lustre-MDT0000 [ 827.960204] Lustre: server umount lustre-MDT0000 complete [ 829.412841] 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 [ 829.416077] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 829.419288] LustreError: 26280:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 829.419300] LustreError: 26280:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 4 previous similar messages [ 829.433181] Lustre: Skipped 3 previous similar messages [ 838.613047] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 838.780668] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 838.943765] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 838.948949] Lustre: Skipped 1 previous similar message [ 838.981452] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 843.759559] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 844.270906] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 844.274630] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 844.296156] Lustre: Skipped 3 previous similar messages [ 844.311727] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 844.325873] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 844.331465] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 847.208095] Lustre: *** cfs_fail_loc=1505, val=0*** [ 855.005897] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 21:54:46 (1787190886) [ 860.474353] Lustre: *** cfs_fail_loc=1603, val=0*** [ 867.729756] Lustre: Failing over lustre-MDT0000 [ 867.826389] Lustre: server umount lustre-MDT0000 complete [ 869.867139] 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 [ 869.889293] Lustre: Skipped 3 previous similar messages [ 878.404415] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 878.517683] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 878.699515] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 882.798210] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 883.687101] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 883.693154] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 883.714067] Lustre: Skipped 3 previous similar messages [ 883.737736] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 883.758887] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 883.759075] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 891.865467] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 21:55:23 (1787190923) [ 893.340967] Lustre: 26281:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 893.353774] Lustre: 26281:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 644 previous similar messages [ 893.360025] Lustre: 26281:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 893.373354] Lustre: 26281:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 893.384180] Lustre: 26281:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 893.390851] Lustre: 26281:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 893.403460] Lustre: 26281:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 893.412450] Lustre: 26281:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 893.423427] Lustre: 26281:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 893.432684] Lustre: 26281:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 893.442499] Lustre: 26281:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 893.450765] Lustre: 26281:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 898.637916] Lustre: *** cfs_fail_loc=1604, val=0*** [ 906.276166] Lustre: Failing over lustre-MDT0000 [ 906.390923] Lustre: server umount lustre-MDT0000 complete [ 909.281743] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 909.282609] 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 [ 909.283833] LustreError: 28088:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 909.283842] LustreError: 28088:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 15 previous similar messages [ 909.368898] Lustre: Skipped 3 previous similar messages [ 916.984665] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 917.079098] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 917.246250] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 921.360191] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 922.594427] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 922.598256] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 922.618745] Lustre: Skipped 3 previous similar messages [ 922.646029] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 922.670034] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 922.673438] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 930.472943] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 21:56:01 (1787190961) [ 936.204092] Lustre: *** cfs_fail_loc=1605, val=0*** [ 943.992630] Lustre: Failing over lustre-MDT0000 [ 944.057598] Lustre: server umount lustre-MDT0000 complete [ 948.194106] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 948.204859] 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 [ 948.231887] Lustre: Skipped 3 previous similar messages [ 953.555521] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 953.654794] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 953.812888] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 957.639471] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 958.950641] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 958.961232] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 958.967341] Lustre: Skipped 3 previous similar messages [ 958.974477] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 958.981980] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 958.983264] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 965.981161] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 21:56:37 (1787190997) [ 971.498133] Lustre: *** cfs_fail_loc=161d, val=0*** [ 978.780497] Lustre: Failing over lustre-MDT0000 [ 978.890448] Lustre: server umount lustre-MDT0000 complete [ 979.425754] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 987.560621] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 987.736720] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 987.874870] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 987.879023] Lustre: Skipped 3 previous similar messages [ 987.932638] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 993.250934] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 993.251916] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 993.276675] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 993.332517] Lustre: Skipped 3 previous similar messages [ 993.358832] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 993.375958] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 993.386829] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 1003.071861] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 21:57:14 (1787191034) [ 1005.140411] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1015.522990] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 21:57:26 (1787191046) [ 1020.750895] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1021.631260] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1021.638027] Lustre: 26281:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 279, rollback = 2 [ 1021.647932] Lustre: 26281:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1292 previous similar messages [ 1021.661824] Lustre: 26281:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1021.673913] Lustre: 26281:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1292 previous similar messages [ 1021.681423] Lustre: 26281:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 2/2/0, xattr_set: 4/279/0 [ 1021.687413] Lustre: 26281:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1292 previous similar messages [ 1021.693518] Lustre: 26281:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1021.699057] Lustre: 26281:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1292 previous similar messages [ 1021.706055] Lustre: 26281:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/16/0, delete: 0/0/0 [ 1021.713989] Lustre: 26281:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1292 previous similar messages [ 1021.726818] Lustre: 26281:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 1021.734511] Lustre: 26281:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1292 previous similar messages [ 1031.350414] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 21:57:42 (1787191062) [ 1066.042209] Lustre: Failing over lustre-MDT0000 [ 1066.159380] Lustre: server umount lustre-MDT0000 complete [ 1070.049676] 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 [ 1070.066436] Lustre: Skipped 4 previous similar messages [ 1070.074213] LustreError: 26282:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1070.095400] LustreError: 26282:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 26 previous similar messages [ 1071.267919] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1079.451627] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1086.440506] Lustre: 16434:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787191102/real 1787191102] req@ffff9f1651726300 x1874005004606080/t0(0) o400->MGC192.168.203.153@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1787191118 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1086.493172] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1090.591621] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1090.611578] Lustre: lustre-MDT0000: reset Object Index mappings [ 1096.677253] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xbc0c489b8ab2432f [ 1096.697927] Lustre: MGC192.168.203.153@tcp: Connection restored to 0@lo (at 0@lo) [ 1096.708091] Lustre: Skipped 3 previous similar messages [ 1096.944620] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1101.817782] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1102.309028] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1102.322761] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1102.329578] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1102.332173] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1105.772238] LustreError: 42938:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1105.838308] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1107.874273] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1107.878473] Lustre: Skipped 1 previous similar message [ 1116.011089] Lustre: Failing over lustre-MDT0000 [ 1116.100609] Lustre: server umount lustre-MDT0000 complete [ 1117.664651] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1126.436522] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1130.582214] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1132.023602] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1132.032272] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1133.338245] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1139.486946] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 21:59:30 (1787191170) [ 1141.875456] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1149.430584] Lustre: Failing over lustre-MDT0000 [ 1149.506706] Lustre: server umount lustre-MDT0000 complete [ 1152.480958] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1152.483883] 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 [ 1152.512568] Lustre: Skipped 7 previous similar messages [ 1154.297670] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1162.971150] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1168.337375] Lustre: 16432:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787191184/real 1787191184] req@ffff9f1549ae5500 x1874005004696192/t0(0) o400->MGC192.168.203.153@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1787191200 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1172.068557] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1172.094079] Lustre: lustre-MDT0000: reset Object Index mappings [ 1178.593454] LustreError: 16430:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9f1541876680 x1874005004704256/t0(0) o250->MGC192.168.203.153@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1178.807558] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1178.822092] Lustre: Skipped 1 previous similar message [ 1182.677850] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1184.229152] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1184.231225] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1184.240257] Lustre: Skipped 1 previous similar message [ 1184.267671] Lustre: Skipped 8 previous similar messages [ 1184.279197] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1184.286546] Lustre: Skipped 1 previous similar message [ 1184.297113] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1184.301049] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1186.031105] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1186.034642] Lustre: Skipped 2 previous similar messages [ 1197.761250] Lustre: Failing over lustre-MDT0000 [ 1197.873121] Lustre: server umount lustre-MDT0000 complete [ 1199.586045] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1207.960239] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1212.884845] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1213.433766] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1213.434173] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1216.433294] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1216.435767] Lustre: Skipped 84 previous similar messages [ 1223.846155] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 22:00:55 (1787191255) [ 1231.379686] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1231.381790] Lustre: Skipped 7 previous similar messages [ 1249.333335] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 22:01:20 (1787191280) [ 1257.022374] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1257.033592] Lustre: Skipped 8 previous similar messages [ 1278.324751] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 22:01:49 (1787191309) [ 1279.730400] Lustre: 28088:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 1279.736577] Lustre: 28088:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1352 previous similar messages [ 1279.742060] Lustre: 28088:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1279.747255] Lustre: 28088:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1352 previous similar messages [ 1279.752047] Lustre: 28088:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1279.756900] Lustre: 28088:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1352 previous similar messages [ 1279.761904] Lustre: 28088:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1279.767138] Lustre: 28088:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1352 previous similar messages [ 1279.772270] Lustre: 28088:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 1279.775288] Lustre: 28088:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1352 previous similar messages [ 1279.779696] Lustre: 28088:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1279.784858] Lustre: 28088:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1352 previous similar messages [ 1289.504452] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1289.518542] Lustre: Skipped 13 previous similar messages [ 1292.509516] Lustre: Failing over lustre-MDT0000 [ 1292.608928] Lustre: server umount lustre-MDT0000 complete [ 1295.331987] 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 [ 1295.341104] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1295.352614] Lustre: Skipped 8 previous similar messages [ 1300.096283] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1300.196800] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1300.202596] LustreError: Skipped 3 previous similar messages [ 1300.320778] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1300.329299] Lustre: Skipped 4 previous similar messages [ 1304.230436] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1305.608820] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:854 to 0x280000401:897) [ 1305.609658] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:853 to 0x2c0000401:897) [ 1312.328311] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 22:02:23 (1787191343) [ 1323.850474] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 1338.058927] Lustre: 53009:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1356.479456] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1359.413878] Lustre: 54145:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1365.484396] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1365.488947] Lustre: Skipped 81 previous similar messages [ 1367.677634] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1368.736141] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1369.760201] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1371.808345] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1371.810861] Lustre: Skipped 1 previous similar message [ 1372.093041] Lustre: Failing over lustre-MDT0000 [ 1372.131457] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1372.140919] Lustre: Skipped 3 previous similar messages [ 1372.208415] Lustre: server umount lustre-MDT0000 complete [ 1377.252722] LustreError: 29676:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1377.284499] LustreError: 29676:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 75 previous similar messages [ 1380.224888] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1380.540223] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1380.545558] Lustre: Skipped 2 previous similar messages [ 1384.517069] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1385.959157] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1385.961595] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1385.974783] Lustre: Skipped 2 previous similar messages [ 1385.979075] Lustre: Skipped 11 previous similar messages [ 1386.010592] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1386.017827] Lustre: Skipped 2 previous similar messages [ 1386.039210] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:946 to 0x2c0000401:961) [ 1386.040590] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 1393.173274] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 22:03:44 (1787191424) [ 1396.197930] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1396.202092] Lustre: Skipped 3 previous similar messages [ 1401.317653] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1401.327675] Lustre: Skipped 3 previous similar messages [ 1406.435962] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1406.445952] Lustre: Skipped 3 previous similar messages [ 1408.992253] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 1409.108328] Lustre: server umount lustre-MDT0000 complete [ 1412.471897] LustreError: 26265:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787191444 with bad export cookie 13550285211735125097 [ 1412.485062] LustreError: 26265:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1412.594972] Lustre: server umount lustre-MDT0001 complete [ 1426.952714] Lustre: server umount lustre-OST0000 complete [ 1439.262285] Lustre: server umount lustre-OST0001 complete [ 1445.666488] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_hostid [ 1453.409826] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 1490.769779] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 1500.048273] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1500.348230] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1500.375961] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1500.385741] Lustre: lustre-MDT0000: new disk, initializing [ 1500.462477] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1505.299139] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1515.929720] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1516.025709] Lustre: 59203: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 [ 1516.064351] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1516.070647] Lustre: Skipped 1 previous similar message [ 1516.077617] Lustre: lustre-MDT0001: new disk, initializing [ 1516.172298] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1516.194342] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1520.294704] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1524.656588] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1530.251592] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1530.498594] Lustre: lustre-OST0000: new disk, initializing [ 1530.504856] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1530.517258] Lustre: 60837:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1531.726734] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1531.747905] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1531.839866] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1536.842917] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1546.324519] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1546.417821] Lustre: lustre-OST0001: new disk, initializing [ 1546.421417] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1546.427591] Lustre: 61706:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1547.573295] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1547.584455] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1547.655632] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1552.562785] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1561.488903] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1564.950871] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1573.236976] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1574.142577] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1574.146410] Lustre: Skipped 19 previous similar messages [ 1577.771916] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1577.773475] Lustre: Skipped 2 previous similar messages [ 1595.349395] Lustre: Failing over lustre-MDT0000 [ 1595.527418] Lustre: server umount lustre-MDT0000 complete [ 1598.437274] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1598.441807] LustreError: Skipped 2 previous similar messages [ 1598.449390] 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 [ 1598.466469] Lustre: Skipped 8 previous similar messages [ 1604.785587] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1604.893314] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1604.899831] LustreError: Skipped 2 previous similar messages [ 1608.772491] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1610.217377] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1610.227405] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1610.227540] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1615.889345] Lustre: Failing over lustre-MDT0000 [ 1615.967889] Lustre: server umount lustre-MDT0000 complete [ 1624.240611] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1628.415700] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1629.692530] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1629.704865] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1629.704867] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1633.348611] Lustre: Failing over lustre-MDT0000 [ 1633.426915] Lustre: server umount lustre-MDT0000 complete [ 1641.288752] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1641.553809] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1641.569384] Lustre: Skipped 2 previous similar messages [ 1646.523242] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1646.565887] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1646.573678] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1646.574445] Lustre: Skipped 2 previous similar messages [ 1646.613725] Lustre: Skipped 11 previous similar messages [ 1646.650275] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1646.672622] Lustre: Skipped 2 previous similar messages [ 1646.680709] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1646.685792] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1653.432030] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1667.516952] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 22:08:19 (1787191699) [ 1682.271143] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 1699.159383] Lustre: 68662:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1719.366167] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1722.748993] Lustre: 69797:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1825.801451] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 22:10:57 (1787191857) [ 1863.607112] Lustre: 70605:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 278, rollback = 2 [ 1863.628123] Lustre: 70605:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 17060 previous similar messages [ 1863.647673] Lustre: 70605:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 1863.663746] Lustre: 70605:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1863.676444] Lustre: 70605:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1863.691027] Lustre: 70605:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1863.696324] Lustre: 70605:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1863.705471] Lustre: 70605:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1863.721683] Lustre: 70605:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1863.734773] Lustre: 70605:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1863.740575] Lustre: 70605:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1863.747413] Lustre: 70605:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 17060 previous similar messages [ 1869.403867] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1869.412973] Lustre: Skipped 4 previous similar messages [ 1890.250214] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1890.253061] Lustre: Skipped 7 previous similar messages [ 1922.469882] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 22:12:34 (1787191954) [ 1959.050666] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1967.063266] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1967.067191] Lustre: Skipped 559 previous similar messages [ 1983.076590] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1983.078326] Lustre: Skipped 952 previous similar messages [ 2015.084824] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2015.087197] Lustre: Skipped 1929 previous similar messages [ 2017.744777] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2017.749074] Lustre: Skipped 2599 previous similar messages [ 2225.709515] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 22:17:37 (1787192257) [ 2363.368137] 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 [ 2363.376403] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2363.384464] Lustre: Skipped 11 previous similar messages [ 2363.389980] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2363.403172] LustreError: Skipped 2 previous similar messages [ 2363.435947] Lustre: Skipped 3 previous similar messages [ 2368.484016] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2368.500308] Lustre: Skipped 3 previous similar messages [ 2369.551359] Lustre: server umount lustre-MDT0000 complete [ 2373.057186] LustreError: 73459:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787192405 with bad export cookie 13550285211735144200 [ 2373.059694] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2373.067036] LustreError: 73459:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2373.079491] LustreError: Skipped 2 previous similar messages [ 2373.218725] Lustre: server umount lustre-MDT0001 complete [ 2386.757242] Lustre: server umount lustre-OST0000 complete [ 2389.985752] Lustre: 16434:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787192405/real 1787192405] req@ffff9f154bd59c00 x1874005008746112/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787192421 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2390.707362] Lustre: server umount lustre-OST0001 complete [ 2397.048628] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2405.873801] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2421.473663] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2426.592296] LustreError: 74969:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.203.153@tcp: failed processing log, type 4: rc = -110 [ 2452.256235] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2452.280348] Lustre: Skipped 8 previous similar messages [ 2457.751256] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2461.367021] Lustre: 75552: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. [ 2461.404259] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2464.495755] Lustre: 75552:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2472.478392] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 22:21:43 (1787192503) [ 2484.847240] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 2494.389560] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2494.727215] LustreError: 74994:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2494.738806] LustreError: 74994:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 24 previous similar messages [ 2494.790965] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3271 to 0x280000401:3297) [ 2499.389920] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2506.816468] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2511.151703] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2513.385939] Lustre: 78214:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2526.458048] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2526.646521] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2526.651994] Lustre: Skipped 2 previous similar messages [ 2531.828290] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2532.678310] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2539.470959] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2542.605897] Lustre: 79708:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2543.560846] Lustre: 77067:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 2543.568553] Lustre: 77067:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 22021 previous similar messages [ 2543.576643] Lustre: 77067:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 2543.583178] Lustre: 77067:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 22021 previous similar messages [ 2543.588138] Lustre: 77067:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2543.594706] Lustre: 77067:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 22021 previous similar messages [ 2543.601816] Lustre: 77067:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2543.611918] Lustre: 77067:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 22021 previous similar messages [ 2543.639670] Lustre: 77067:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 2543.650086] Lustre: 77067:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 22021 previous similar messages [ 2543.666078] Lustre: 77067:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2543.673833] Lustre: 77067:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 22021 previous similar messages [ 2546.816704] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2547.332928] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2547.338916] Lustre: Skipped 3 previous similar messages [ 2554.071815] Lustre: Failing over lustre-OST0000 [ 2554.161385] Lustre: server umount lustre-OST0000 complete [ 2564.419956] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2564.671399] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2566.564807] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2566.605873] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2566.627638] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 2566.631700] Lustre: *** cfs_fail_loc=215, val=0*** [ 2566.633470] Lustre: Skipped 3 previous similar messages [ 2566.658118] Lustre: Skipped 2 previous similar messages [ 2570.361260] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2571.745294] Lustre: *** cfs_fail_loc=215, val=0*** [ 2571.750690] Lustre: Skipped 1 previous similar message [ 2573.852412] Lustre: 81111: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. [ 2573.867864] Lustre: 81111:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2576.352185] Lustre: Failing over lustre-OST0000 [ 2576.420250] Lustre: server umount lustre-OST0000 complete [ 2583.238648] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2585.023462] Lustre: *** cfs_fail_loc=215, val=0*** [ 2585.030785] Lustre: Skipped 3 previous similar messages [ 2589.071594] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2590.178467] Lustre: *** cfs_fail_loc=215, val=0*** [ 2590.181113] Lustre: Skipped 1 previous similar message [ 2593.763357] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2593.771031] Lustre: Skipped 3 previous similar messages [ 2598.891401] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2598.902226] Lustre: Skipped 3 previous similar messages [ 2599.731255] Lustre: server umount lustre-MDT0000 complete [ 2602.908580] LustreError: 74975:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787192634 with bad export cookie 13550285211736709141 [ 2602.908580] LustreError: 74977:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787192634 with bad export cookie 13550285211736709141 [ 2603.028887] Lustre: server umount lustre-MDT0001 complete [ 2616.802725] Lustre: server umount lustre-OST0000 complete [ 2619.360429] Lustre: 16434:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787192635/real 1787192635] req@ffff9f165eef5f80 x1874005008836096/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787192651 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2620.208791] Lustre: server umount lustre-OST0001 complete [ 2628.183184] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 22:24:19 (1787192659) [ 2641.879898] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 2651.703934] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2656.049970] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2662.531039] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2662.697791] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2662.703213] Lustre: Skipped 3 previous similar messages [ 2666.318210] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2668.609227] Lustre: 85491:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2674.754070] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2678.008355] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 2681.083349] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2689.306913] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2694.643440] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 2695.494921] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2702.241227] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2705.538402] Lustre: 87361:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2762.928429] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 22:26:34 (1787192794) [ 2775.254530] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 22:26:46 (1787192806) [ 2776.411782] Lustre: *** cfs_fail_loc=160f, val=0*** [ 2786.619181] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 22:26:57 (1787192817) [ 2790.074995] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2790.080542] Lustre: Skipped 3 previous similar messages [ 2837.987625] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2837.992417] Lustre: Skipped 3 previous similar messages [ 2843.603789] Lustre: server umount lustre-MDT0000 complete [ 2847.354391] LustreError: 84334:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787192879 with bad export cookie 13550285211736717597 [ 2847.368688] LustreError: 84334:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2847.561341] Lustre: server umount lustre-MDT0001 complete [ 2861.722896] Lustre: server umount lustre-OST0000 complete [ 2864.609640] Lustre: 16431:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787192880/real 1787192880] req@ffff9f154bc7a300 x1874005009076480/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787192896 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2865.492818] Lustre: server umount lustre-OST0001 complete [ 2881.521435] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 2891.126915] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2896.264534] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2904.372669] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2908.999850] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2911.992921] Lustre: 94091:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2917.972443] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2924.334642] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2929.530990] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 2932.594749] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2932.810683] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2932.818753] Lustre: Skipped 5 previous similar messages [ 2936.940748] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 2936.952111] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 2937.063132] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 2938.820656] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2946.085123] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2949.919442] Lustre: 95960:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2955.546308] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 22:29:47 (1787192987) [ 2960.474987] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2960.479228] Lustre: Skipped 63 previous similar messages [ 2981.347222] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2981.354226] LustreError: Skipped 3 previous similar messages [ 2981.360299] 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 [ 2981.367271] Lustre: Skipped 18 previous similar messages [ 2981.370563] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2981.373730] Lustre: Skipped 4 previous similar messages [ 2985.253280] Lustre: server umount lustre-MDT0000 complete [ 2989.059974] LustreError: 92931:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787193021 with bad export cookie 13550285211736746010 [ 2989.060792] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2989.067642] LustreError: 92931:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2989.083363] LustreError: Skipped 2 previous similar messages [ 2989.190335] Lustre: server umount lustre-MDT0001 complete [ 3002.938871] Lustre: server umount lustre-OST0000 complete [ 3016.625497] Lustre: server umount lustre-OST0001 complete [ 3032.408130] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 3041.783777] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3045.983158] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3055.207067] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3059.581850] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3062.676270] Lustre: 99992:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3069.194689] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3075.322475] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3080.749148] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3083.872338] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3087.145337] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3087.172936] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3087.310461] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3091.641261] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3099.102718] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3109.582814] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 22:32:21 (1787193141) [ 3113.152678] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3113.154506] Lustre: Skipped 63 previous similar messages [ 3113.319146] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3122.892703] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 22:32:34 (1787193154) [ 3124.973990] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3125.017569] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3125.022972] Lustre: Skipped 3 previous similar messages [ 3136.412843] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 22:32:47 (1787193167) [ 3137.865987] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3139.323386] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 22:32:50 (1787193170) [ 3143.683219] Lustre: 98861:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0001: opcode 2: before 259 < left 421, rollback = 2 [ 3143.689176] Lustre: 98861:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 2099 previous similar messages [ 3143.694123] Lustre: 98861:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 3/12/0, destroy: 0/0/0 [ 3143.700197] Lustre: 98861:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 2099 previous similar messages [ 3143.704557] Lustre: 98861:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 4/4/0, xattr_set: 11/421/0 [ 3143.709564] Lustre: 98861:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2099 previous similar messages [ 3143.717894] Lustre: 98861:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 5/84/0, punch: 0/0/0, quota 1/3/0 [ 3143.725809] Lustre: 98861:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 2099 previous similar messages [ 3143.730577] Lustre: 98861:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 12/215/1, delete: 0/0/0 [ 3143.734983] Lustre: 98861:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2099 previous similar messages [ 3143.739775] Lustre: 98861:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 6/6/0, ref_del: 0/0/0 [ 3143.744150] Lustre: 98861:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2099 previous similar messages [ 3145.161828] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3145.308584] LustreError: 98861:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240002340:0x6c:0x0]/f61 failed: rc = -5 [ 3153.113649] LustreError: 98848:0:(lod_object.c:945:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x61:0x0]:1 for the striped directory [0x240002340:0x7b:0x0] is out of the known LMV EA range [0 - 0], failout [ 3158.308068] LustreError: 100977:0:(lod_object.c:945:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x61:0x0]:1 for the striped directory [0x240002340:0x7b:0x0] is out of the known LMV EA range [0 - 0], failout [ 3158.328182] LustreError: 100977:0:(mdt_handler.c:1498:mdt_getattr_internal()) lustre-MDT0001: getattr error for [0x240002340:0x7b:0x0]: rc = -5 [ 3193.825316] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3193.835581] Lustre: Skipped 4 previous similar messages [ 3197.713290] Lustre: server umount lustre-MDT0000 complete [ 3199.977494] LustreError: 98846:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3199.995352] LustreError: 98846:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 46 previous similar messages [ 3205.138117] LustreError: 101172:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787193237 with bad export cookie 13550285211736760738 [ 3205.148210] LustreError: 101172:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3205.287366] Lustre: server umount lustre-MDT0001 complete [ 3222.315733] Lustre: server umount lustre-OST0000 complete [ 3226.592106] Lustre: 16432:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787193242/real 1787193242] req@ffff9f154d609c00 x1874005009458944/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787193258 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3230.669442] Lustre: server umount lustre-OST0001 complete [ 3247.857960] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing unload_modules_local [ 3250.750291] Key type lgssc unregistered [ 3251.110895] LNet: 105695:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3251.128402] LNetError: 105695:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3251.147867] LNet: Removed LNI 192.168.203.153@tcp [ 3252.324382] Key type .llcrypt unregistered [ 3252.327574] Key type ._llcrypt unregistered [ 3274.071685] Key type ._llcrypt registered [ 3274.076211] Key type .llcrypt registered [ 3274.182726] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_hostid [ 3286.233147] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 3287.445906] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3287.524815] alg: No test for adler32 (adler32-zlib) [ 3288.672899] Lustre: Lustre: Build Version: 2.17.57_44_gafaaa93 [ 3288.943200] LNet: Added LNI 192.168.203.153@tcp [8/256/0/180] [ 3290.632325] Key type lgssc registered [ 3291.746444] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3338.104207] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 3349.980687] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3350.004840] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3351.194047] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3351.215084] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3351.220735] Lustre: lustre-MDT0000: new disk, initializing [ 3351.255757] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3351.272756] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3354.736604] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3368.048638] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3368.244719] Lustre: 110129: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 [ 3368.305388] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3368.316413] Lustre: Skipped 1 previous similar message [ 3368.326161] Lustre: lustre-MDT0001: new disk, initializing [ 3368.425779] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3368.487675] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3368.507796] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3373.444219] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3378.339101] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3387.280513] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3387.470979] Lustre: lustre-OST0000: new disk, initializing [ 3387.474805] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3387.478982] Lustre: 112065:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3387.523881] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3392.604484] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3392.610444] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3392.695908] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3393.963177] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3405.655579] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3405.846555] Lustre: lustre-OST0001: new disk, initializing [ 3405.852073] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3405.857436] Lustre: 113089:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3405.946029] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3412.172196] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3416.101387] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3416.113075] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3416.150422] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3421.651212] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3430.474838] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3435.900389] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 22:37:47 (1787193467) === [ 3442.930737] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 22:37:54 (1787193474) [ 3443.123844] Lustre: 110134:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3443.154904] Lustre: 110134:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3443.172722] Lustre: 110134:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3443.197771] Lustre: 110134:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3443.205911] Lustre: 110134:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3443.217118] Lustre: 110134:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3443.733704] Lustre: 113096:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3443.746965] Lustre: 113096:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 9 previous similar messages [ 3443.756038] Lustre: 113096:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3443.767818] Lustre: 113096:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3443.779315] Lustre: 113096:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3443.789166] Lustre: 113096:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3443.809478] Lustre: 113096:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/1, punch: 0/0/0, quota 7/369/2 [ 3443.822392] Lustre: 113096:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3443.830721] Lustre: 113096:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 3443.836465] Lustre: 113096:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3443.842135] Lustre: 113096:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3443.848587] Lustre: 113096:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3444.739533] Lustre: 110133:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 3444.745180] Lustre: 110133:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 134 previous similar messages [ 3444.755673] Lustre: 110133:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3444.761634] Lustre: 110133:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 134 previous similar messages [ 3444.787141] Lustre: 110134:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3444.797178] Lustre: 110134:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 137 previous similar messages [ 3444.810039] Lustre: 110134:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3444.823617] Lustre: 110134:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 137 previous similar messages [ 3444.834789] Lustre: 110134:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3444.840956] Lustre: 110134:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 137 previous similar messages [ 3444.848528] Lustre: 110134:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3444.854530] Lustre: 110134:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 137 previous similar messages [ 3446.661212] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3456.461520] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 22:38:07 (1787193487) [ 3457.687142] Lustre: 110134:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3457.699256] Lustre: 110134:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 164 previous similar messages [ 3457.712302] Lustre: 110134:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3457.724571] Lustre: 110134:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 164 previous similar messages [ 3457.733346] Lustre: 110134:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3457.742641] Lustre: 110134:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 161 previous similar messages [ 3457.751881] Lustre: 110134:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3457.760834] Lustre: 110134:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 161 previous similar messages [ 3457.771325] Lustre: 110134:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3457.780331] Lustre: 110134:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 161 previous similar messages [ 3457.788970] Lustre: 110134:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3457.800650] Lustre: 110134:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 161 previous similar messages [ 3458.839072] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3463.154981] Lustre: 112056:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 3463.178373] Lustre: 112056:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 11 previous similar messages [ 3463.193251] Lustre: 112056:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3463.206763] Lustre: 112056:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3463.217599] Lustre: 112056:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 3463.231458] Lustre: 112056:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3463.238828] Lustre: 112056:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3463.260372] Lustre: 112056:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3463.277547] Lustre: 112056:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3463.290703] Lustre: 112056:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3463.296585] Lustre: 112056:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3463.303974] Lustre: 112056:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 3469.425390] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 22:38:20 (1787193500) [ 3472.063547] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3472.072044] Lustre: Skipped 1 previous similar message [ 3473.092892] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3473.097778] Lustre: Skipped 3 previous similar messages [ 3490.603459] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3492.200855] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 22:38:43 (1787193523) [ 3492.616669] Lustre: 110133:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3492.624576] Lustre: 110133:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 23 previous similar messages [ 3492.635259] Lustre: 110133:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3492.645732] Lustre: 110133:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 3492.651100] Lustre: 110133:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3492.657139] Lustre: 110133:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 3492.672216] Lustre: 110133:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3492.676479] Lustre: 110133:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 3492.684523] Lustre: 110133:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3492.689137] Lustre: 110133:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 3492.694513] Lustre: 110133:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3492.699137] Lustre: 110133:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 3494.682374] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3494.793493] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3496.829121] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3496.832241] Lustre: Skipped 1 previous similar message [ 3513.377577] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 22:39:04 (1787193544) [ 3513.833760] Lustre: 110133:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3513.840513] Lustre: 110133:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 24 previous similar messages [ 3513.848620] Lustre: 110133:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3513.852695] Lustre: 110133:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3513.857167] Lustre: 110133:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3513.861736] Lustre: 110133:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3513.865677] Lustre: 110133:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3513.870768] Lustre: 110133:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3513.876419] Lustre: 110133:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3513.880764] Lustre: 110133:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3513.885642] Lustre: 110133:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3513.894364] Lustre: 110133:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3515.408967] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3515.410884] Lustre: Skipped 5 previous similar messages [ 3549.155087] 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 [ 3549.158622] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3549.168491] Lustre: Skipped 3 previous similar messages [ 3549.187026] Lustre: Skipped 3 previous similar messages [ 3554.273290] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3554.280772] Lustre: Skipped 3 previous similar messages [ 3554.853118] Lustre: server umount lustre-MDT0000 complete [ 3558.241145] LustreError: 113088:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787193590 with bad export cookie 10831564757780546040 [ 3558.247097] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3558.255155] LustreError: 113088:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3558.378365] Lustre: server umount lustre-MDT0001 complete [ 3571.238334] Lustre: server umount lustre-OST0000 complete [ 3584.988307] Lustre: server umount lustre-OST0001 complete [ 3600.944618] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 3609.811577] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3610.164234] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3614.881448] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3615.200730] LustreError: 118806:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3615.214178] LustreError: 118806:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 3620.341749] LustreError: 118807:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3624.478994] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3624.718360] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3629.464765] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3632.160977] Lustre: 119947:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3639.085163] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3646.699418] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3649.570298] LustreError: 120300:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3649.584221] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 3654.626532] LustreError: 120830:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3654.876044] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3655.183985] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3655.205027] Lustre: Skipped 1 previous similar message [ 3656.258311] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 3656.266309] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 3656.461472] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3661.593566] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3668.357600] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3671.171256] Lustre: 121818:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3683.591574] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 22:41:55 (1787193715) [ 3683.898369] Lustre: 118801:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3683.905982] Lustre: 118801:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3683.921765] Lustre: 118801:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3683.935922] Lustre: 118801:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3683.955783] Lustre: 118801:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3683.964397] Lustre: 118801:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3683.970207] Lustre: 118801:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3683.974606] Lustre: 118801:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3683.981176] Lustre: 118801:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3683.986864] Lustre: 118801:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3683.996968] Lustre: 118801:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3684.006459] Lustre: 118801:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3685.388777] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3685.393283] Lustre: Skipped 3 previous similar messages [ 3722.209037] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3722.220695] 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 [ 3722.231904] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3724.791760] Lustre: server umount lustre-MDT0000 complete [ 3727.842077] LustreError: 118807:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3727.859269] LustreError: 118807:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 3728.047315] LustreError: 118788:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787193760 with bad export cookie 10831564757780561293 [ 3728.067725] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3728.233242] Lustre: server umount lustre-MDT0001 complete [ 3741.217888] Lustre: server umount lustre-OST0000 complete [ 3754.770414] Lustre: server umount lustre-OST0001 complete [ 3769.863860] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 3778.101469] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3778.329603] LustreError: 124384:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3778.380296] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3782.470784] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3789.739410] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3793.759646] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3796.469236] Lustre: 125523:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3802.869589] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3804.195277] LustreError: 125877:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3804.214331] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 3804.219840] LustreError: 125877:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 3808.328740] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3814.402896] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 3816.034607] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3821.554072] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 3821.554233] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 3821.884572] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3829.082590] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3832.377963] Lustre: 127391:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3837.573411] Lustre: 124385:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 3837.590296] Lustre: 124385:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3837.597247] Lustre: 124385:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3837.606919] Lustre: 124385:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3837.611352] Lustre: 124385:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 3837.616908] Lustre: 124385:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3837.624339] Lustre: 124385:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 3837.629700] Lustre: 124385:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3837.635046] Lustre: 124385:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 3837.640802] Lustre: 124385:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3837.656063] Lustre: 124385:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3837.669292] Lustre: 124385:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3837.721711] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3861.895489] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 22:44:53 (1787193893) [ 3864.722023] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3864.724660] Lustre: Skipped 3 previous similar messages [ 3871.118318] Lustre: *** cfs_fail_loc=161c, val=0*** [ 3895.963816] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 22:45:27 (1787193927) [ 3897.924242] Lustre: *** cfs_fail_loc=162e, val=0*** [ 3897.928217] Lustre: *** cfs_fail_loc=162e, val=0*** [ 3897.931252] Lustre: Skipped 7 previous similar messages [ 3910.010696] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 22:45:41 (1787193941) [ 3926.866331] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 22:45:58 (1787193958) [ 3937.298530] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 22:46:08 (1787193968) [ 3940.150416] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3940.178641] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3940.182860] Lustre: Skipped 3 previous similar messages [ 3944.614842] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.203.53@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 3945.704748] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.203.53@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 3952.647641] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 22:46:23 (1787193983) [ 3968.122511] Lustre: 126596:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 3968.136310] Lustre: 126596:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 131 previous similar messages [ 3968.153295] Lustre: 126596:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3968.163296] Lustre: 126596:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 3968.174260] Lustre: 126596:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3968.189696] Lustre: 126596:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 3968.199584] Lustre: 126596:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/1, punch: 0/0/0, quota 1/3/0 [ 3968.213504] Lustre: 126596:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 3968.228323] Lustre: 126596:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 3968.242273] Lustre: 126596:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 3968.253515] Lustre: 126596:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3968.262264] Lustre: 126596:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 131 previous similar messages [ 3976.217494] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 22:46:47 (1787194007) [ 3982.527903] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 22:46:53 (1787194013) [ 3993.612920] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 22:47:04 (1787194024) [ 3995.687160] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3995.696469] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3995.702055] Lustre: Skipped 1 previous similar message [ 4004.242838] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 22:47:15 (1787194035) [ 4005.584848] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4005.593351] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4016.031915] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 22:47:27 (1787194047) [ 4017.755714] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4029.902497] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4031.379957] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 22:47:42 (1787194062) [ 4036.481820] Lustre: *** cfs_fail_loc=1621, val=127*** [ 4036.485327] Lustre: Skipped 1 previous similar message [ 4038.915117] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4058.585115] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 22:48:10 (1787194090) [ 4060.502874] Lustre: Failing over lustre-MDT0000 [ 4060.618394] Lustre: server umount lustre-MDT0000 complete [ 4061.154129] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4061.166327] 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 [ 4061.179269] Lustre: Skipped 3 previous similar messages [ 4061.190649] LustreError: 124385:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4061.202584] LustreError: 124385:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 4068.673305] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4068.772904] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4068.873409] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4068.878988] Lustre: Skipped 3 previous similar messages [ 4068.911787] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4069.746745] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4072.428426] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4073.958413] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4074.012915] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 4074.023777] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 4074.024511] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 4074.109855] LustreError: 124379:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4082.452469] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 22:48:34 (1787194114) [ 4084.225066] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4084.402320] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4084.404365] Lustre: Skipped 1 previous similar message [ 4094.904050] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 22:48:45 (1787194125) [ 4096.515275] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4106.464415] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 22:48:57 (1787194137) [ 4108.212969] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4119.943593] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 22:49:11 (1787194151) [ 4131.193649] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 22:49:22 (1787194162) [ 4132.338289] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4132.341064] Lustre: Skipped 1 previous similar message [ 4140.026253] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 22:49:31 (1787194171) [ 4151.022120] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 22:49:42 (1787194182) [ 4156.358863] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4156.362915] Lustre: Skipped 1 previous similar message [ 4168.868150] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 22:50:00 (1787194200) [ 4170.553768] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4170.556496] Lustre: Skipped 4 previous similar messages [ 4181.451799] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 22:50:12 (1787194212) [ 4206.701242] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 22:50:38 (1787194238) [ 4208.755867] LustreError: 124381:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 4213.596881] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 22:50:45 (1787194245) [ 4246.111529] Lustre: Failing over lustre-MDT0000 [ 4246.194571] Lustre: server umount lustre-MDT0000 complete [ 4248.032912] 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 [ 4248.033595] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4248.045770] Lustre: Skipped 4 previous similar messages [ 4248.047134] LustreError: 124380:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4248.077571] LustreError: 124380:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 13 previous similar messages [ 4254.114189] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4254.240386] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4254.404956] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4254.446387] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4257.984437] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4259.809193] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4259.811466] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4259.822221] Lustre: Skipped 3 previous similar messages [ 4259.843715] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4259.852179] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:193) [ 4259.852592] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:321) [ 4260.446955] Lustre: 143113:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 264, rollback = 2 [ 4260.452489] Lustre: 143113:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 776 previous similar messages [ 4260.462981] Lustre: 143113:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 4260.471559] Lustre: 143113:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 776 previous similar messages [ 4260.476778] Lustre: 143113:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/264/0 [ 4260.489183] Lustre: 143113:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 776 previous similar messages [ 4260.494298] Lustre: 143113:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 1/3/0 [ 4260.497762] Lustre: 143113:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 776 previous similar messages [ 4260.501383] Lustre: 143113:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/32/1, delete: 1/1/0 [ 4260.514953] Lustre: 143113:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 776 previous similar messages [ 4260.525496] Lustre: 143113:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 4260.535647] Lustre: 143113:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 776 previous similar messages [ 4268.859364] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 22:51:40 (1787194300) [ 4281.942587] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 22:51:52 (1787194312) [ 4295.948133] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 22:52:07 (1787194327) [ 4297.214678] Lustre: *** cfs_fail_loc=1629, val=0*** [ 4297.216637] Lustre: Skipped 9 previous similar messages [ 4308.077548] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 22:52:19 (1787194339) [ 4312.781154] Lustre: Failing over lustre-MDT0000 [ 4312.883374] Lustre: server umount lustre-MDT0000 complete [ 4316.133382] 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 [ 4316.136386] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4316.144892] Lustre: Skipped 4 previous similar messages [ 4319.842985] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4319.928815] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4320.067159] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4323.510639] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4325.094887] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4325.100212] Lustre: lustre-MDT0000: Denying connection for new client 786bfc22-d7a5-4acd-96a8-88b9e06f17b6 (at 192.168.203.53@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 4325.346680] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4325.351521] Lustre: Skipped 3 previous similar messages [ 4325.369673] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4325.378764] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:225) [ 4325.379503] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:353) [ 4336.143430] Lustre: Failing over lustre-MDT0000 [ 4336.210194] Lustre: server umount lustre-MDT0000 complete [ 4340.705081] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4340.708359] 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 [ 4340.738283] Lustre: Skipped 4 previous similar messages [ 4343.105325] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4343.223810] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4343.491559] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4345.703803] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4347.134581] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4348.908959] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4348.915852] Lustre: Skipped 3 previous similar messages [ 4348.933319] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 4348.949653] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:355 to 0x280000401:385) [ 4348.952501] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:257) [ 4354.691744] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 22:53:06 (1787194386) [ 4367.399387] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 22:53:18 (1787194398) [ 4377.669590] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 22:53:29 (1787194409) [ 4414.084630] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 22:54:05 (1787194445) [ 4423.468123] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 22:54:15 (1787194455) [ 4429.761539] LustreError: 148872:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4431.425574] Lustre: Failing over lustre-OST0000 [ 4431.480531] Lustre: server umount lustre-OST0000 complete [ 4432.784408] LustreError: 148872:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 4432.792542] LustreError: 148872:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4433.017066] LustreError: 148872:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 4433.027279] LustreError: lustre-OST0000-osc-MDT0000: operation lfsck_notify to node 0@lo failed: rc = -107 [ 4433.032172] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4433.050360] LustreError: 125877:0:(ldlm_lib.c:1190: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. [ 4433.061807] LustreError: 125877:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 13 previous similar messages [ 4442.223821] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4442.365959] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4443.684033] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4443.709801] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4443.713726] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4443.724430] Lustre: Skipped 3 previous similar messages [ 4447.002451] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4453.352319] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 22:54:44 (1787194484) [ 4465.011499] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 4480.510088] Lustre: 151673:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4503.516819] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4506.654414] Lustre: 152806:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4516.439675] LustreError: 152923:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4519.355934] Lustre: Failing over lustre-MDT0001 [ 4519.398836] 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 [ 4519.401264] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4519.418443] Lustre: Skipped 3 previous similar messages [ 4519.421969] Lustre: Skipped 4 previous similar messages [ 4519.465137] LustreError: 152923:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 4519.546780] LustreError: 152922:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4519.557928] LustreError: 152922:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 4519.602900] Lustre: server umount lustre-MDT0001 complete [ 4522.072078] LustreError: 152922:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 4532.589532] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4532.838774] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4532.850345] Lustre: Skipped 3 previous similar messages [ 4532.882078] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4537.182658] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4538.339609] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4538.343574] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4538.365560] Lustre: Skipped 1 previous similar message [ 4538.372854] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4538.400500] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:97) [ 4538.404041] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:97) [ 4544.233864] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 22:56:15 (1787194575) [ 4556.233149] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 4570.209393] Lustre: 155641:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4588.135161] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4592.043592] Lustre: 156775:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4611.418279] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 22:57:22 (1787194642) [ 4612.811568] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 4614.075485] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 22:57:25 (1787194645) [ 4620.006798] Lustre: *** cfs_fail_loc=1631, val=0*** [ 4629.984951] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4629.992519] LustreError: Skipped 1 previous similar message [ 4629.998117] 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 [ 4630.016398] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4630.031748] Lustre: Skipped 1 previous similar message [ 4630.495088] Lustre: server umount lustre-MDT0000 complete [ 4632.881795] LustreError: 140543:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787194664 with bad export cookie 10831564757780634142 [ 4632.882142] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4632.891845] LustreError: 140543:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 4633.012838] Lustre: server umount lustre-MDT0001 complete [ 4646.132283] Lustre: server umount lustre-OST0000 complete [ 4659.278596] Lustre: server umount lustre-OST0001 complete [ 4673.301380] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 4683.463737] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4687.973288] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4693.987959] LustreError: 159530:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4694.002165] LustreError: 159530:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 17 previous similar messages [ 4695.690404] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4699.338395] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4701.689426] Lustre: 160669:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4706.913556] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4708.204194] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 4712.032371] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4720.633074] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:129) [ 4720.805791] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4725.670828] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4726.248910] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:129) [ 4726.258833] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 4731.914324] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4735.696292] Lustre: 162539:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4748.001934] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 22:59:39 (1787194779) [ 4749.554950] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 4751.288115] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 22:59:42 (1787194782) [ 4752.754131] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 4754.623231] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 22:59:45 (1787194785) [ 4755.935712] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 4757.598556] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 22:59:49 (1787194789) [ 4768.230304] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 22:59:59 (1787194799) [ 4780.880616] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 23:00:12 (1787194812) [ 4781.072373] Lustre: 159525:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0001: opcode 2: before 250 < left 336, rollback = 2 [ 4781.083972] Lustre: 159525:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1650 previous similar messages [ 4781.095029] Lustre: 159525:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 3/12/6, destroy: 0/0/0 [ 4781.104504] Lustre: 159525:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1651 previous similar messages [ 4781.115508] Lustre: 159525:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 2/2/0, xattr_set: 7/336/0 [ 4781.121673] Lustre: 159525:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1650 previous similar messages [ 4781.127614] Lustre: 159525:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 5/84/0, punch: 0/0/0, quota 1/3/0 [ 4781.133701] Lustre: 159525:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1651 previous similar messages [ 4781.138894] Lustre: 159525:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 10/203/4, delete: 0/0/0 [ 4781.144101] Lustre: 159525:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1651 previous similar messages [ 4781.149156] Lustre: 159525:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 4/4/0, ref_del: 0/0/0 [ 4781.154302] Lustre: 159525:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1651 previous similar messages [ 4792.949353] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 23:00:24 (1787194824) [ 4805.776713] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 23:00:37 (1787194837) [ 4825.078952] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 23:00:56 (1787194856) [ 4858.076246] Lustre: *** cfs_fail_loc=1632, val=0*** [ 4869.205507] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 23:01:40 (1787194900) [ 4871.496119] Lustre: Failing over lustre-MDT0001 [ 4871.584842] Lustre: server umount lustre-MDT0001 complete [ 4874.722470] 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 [ 4874.731366] Lustre: Skipped 4 previous similar messages [ 4877.350665] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4877.527590] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4877.527869] Lustre: lustre-MDT0001: Aborting client recovery [ 4877.538248] LustreError: 166331:0:(ldlm_lib.c:3029:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 4877.543444] Lustre: 166355:0:(ldlm_lib.c:2429:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4877.550696] Lustre: 166355:0:(genops.c:1601:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client dd984c20-3ec9-43ae-9162-6c535d63bc10@ [ 4877.564213] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 4877.570615] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 4877.582411] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 4877.601179] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 4877.601818] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:161) [ 4881.042432] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4882.920517] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 4882.931550] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4882.937439] Lustre: Skipped 3 previous similar messages [ 4887.206358] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 4887.473672] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 4892.322372] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 23:02:03 (1787194923) [ 4899.251788] Lustre: *** cfs_fail_loc=1600, val=3*** [ 4901.701330] Lustre: Failing over lustre-MDT0000 [ 4901.777160] Lustre: server umount lustre-MDT0000 complete [ 4903.404555] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4909.086213] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4909.230851] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4912.956754] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4912.998733] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4914.676649] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 4914.694433] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 4914.698855] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 4920.601405] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 23:02:32 (1787194952) [ 4943.471119] Lustre: Failing over lustre-OST0000 [ 4943.592557] Lustre: server umount lustre-OST0000 complete [ 4949.699833] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 4959.744933] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4959.889205] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4959.902379] Lustre: Skipped 3 previous similar messages [ 4961.385841] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 4961.553884] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 4961.556560] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4961.575961] Lustre: Skipped 5 previous similar messages [ 4965.633631] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4973.581886] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 4973.972974] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 4979.392455] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 4979.620601] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 4984.955119] Lustre: DEBUG MARKER: oleg353-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff8eea63d7d000.ost_server_uuid 50 [ 4986.672790] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8eea63d7d000.ost_server_uuid in FULL state after 0 sec [ 5026.786104] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5026.791573] Lustre: Skipped 3 previous similar messages [ 5031.351401] Lustre: server umount lustre-MDT0000 complete [ 5037.011167] LustreError: 159510:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787195068 with bad export cookie 10831564757780717015 [ 5037.011360] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5037.021134] LustreError: 159510:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5037.053507] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5037.056870] Lustre: Skipped 1 previous similar message [ 5037.151964] Lustre: server umount lustre-MDT0001 complete [ 5045.012035] Lustre: server umount lustre-OST0000 complete [ 5050.437958] Lustre: server umount lustre-OST0001 complete [ 5061.946838] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing unload_modules_local [ 5064.618609] Key type lgssc unregistered [ 5064.881250] LNet: 175462:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5064.887455] LNetError: 175462:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5064.900917] LNet: Removed LNI 192.168.203.153@tcp [ 5065.935149] Key type .llcrypt unregistered [ 5065.937362] Key type ._llcrypt unregistered [ 5084.256579] Key type ._llcrypt registered [ 5084.258748] Key type .llcrypt registered [ 5084.342668] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_hostid [ 5099.115589] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 5100.232136] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 5100.245947] alg: No test for adler32 (adler32-zlib) [ 5101.343371] Lustre: Lustre: Build Version: 2.17.57_44_gafaaa93 [ 5101.548852] LNet: Added LNI 192.168.203.153@tcp [8/256/0/180] [ 5103.216399] Key type lgssc registered [ 5104.678754] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5164.054081] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing load_modules_local [ 5176.280281] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 5176.298973] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5177.470825] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5177.498310] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5177.503415] Lustre: lustre-MDT0000: new disk, initializing [ 5177.578272] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5177.600462] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5180.968067] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5193.400639] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5193.569579] Lustre: 179934: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 [ 5193.611935] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5193.615277] Lustre: Skipped 1 previous similar message [ 5193.619983] Lustre: lustre-MDT0001: new disk, initializing [ 5193.686192] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5193.704189] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5193.712512] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5198.312114] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5203.045896] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5210.771566] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5211.029830] Lustre: lustre-OST0000: new disk, initializing [ 5211.032350] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5211.039532] Lustre: 181875:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5211.108982] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5213.284763] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5213.297508] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5213.365697] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5215.708558] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5226.626345] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5226.720586] Lustre: lustre-OST0001: new disk, initializing [ 5226.726248] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5226.731725] Lustre: 182899:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5226.788029] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5232.356514] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5234.730525] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5234.743600] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5234.837053] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5241.808222] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5247.141019] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5251.941622] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 23:08:03 (1787195283) === [ 5253.246765] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 4983 sec ========= 23:08:04 (1787195284) [ 5254.807632] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 23:08:06 (1787195286) === [ 5257.583521] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 23:08:09 (1787195289) === [ 5265.376912] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5265.378487] 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 [ 5265.385043] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5265.399652] Lustre: Skipped 1 previous similar message [ 5266.728495] Lustre: server umount lustre-MDT0000 complete [ 5272.665575] LustreError: 181874:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787195304 with bad export cookie 16585146895754060462 [ 5272.667192] LustreError: MGC192.168.203.153@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5272.670265] LustreError: 181874:0:(ldlm_lockd.c:2580:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 5272.844848] Lustre: server umount lustre-MDT0001 complete [ 5290.798751] Lustre: server umount lustre-OST0000 complete [ 5292.000332] Lustre: 177096:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787195307/real 1787195307] req@ffff9f167e7e7100 x1874009923858304/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787195323 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5292.048795] 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 [ 5292.063637] Lustre: Skipped 2 previous similar messages [ 5293.793098] Lustre: 177094:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787195309/real 1787195309] req@ffff9f1646c48700 x1874009923858560/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787195325 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5296.096267] Lustre: 177095:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787195312/real 1787195312] req@ffff9f15429d0000 x1874009923858816/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787195328 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5297.395337] Lustre: server umount lustre-OST0001 complete [ 5310.779663] Lustre: DEBUG MARKER: oleg353-server.virtnet: executing unload_modules_local [ 5313.201617] Key type lgssc unregistered [ 5313.437484] LNet: 186374:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5313.451959] LNetError: 186374:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5314.471936] LNet: Removed LNI 192.168.203.153@tcp [ 5315.194131] Key type .llcrypt unregistered [ 5315.198297] Key type ._llcrypt unregistered