[ 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 3.0.0 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-2.fc40 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 477332294 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 0x000f53f0-0x000f53ff] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5200 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1D87 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1C23 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001BE3 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1C97 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1D27 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1D5F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1c23-0xbffe1c96] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1c22] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1c97-0xbffe1d26] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1d27-0xbffe1d5e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1d5f-0xbffe1d86] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001011] APIC: Switch to symmetric I/O mode setup [ 0.003107] x2apic enabled [ 0.004008] Switched APIC routing to physical x2apic. [ 0.005012] kvm-guest: setup PV IPIs [ 0.008412] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009020] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010012] pid_max: default: 32768 minimum: 301 [ 0.011127] LSM: Security Framework initializing [ 0.012048] Yama: becoming mindful. [ 0.013037] SELinux: Initializing. [ 0.014075] *** VALIDATE selinux *** [ 0.018256] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.023354] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.024157] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.025119] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027114] *** VALIDATE tmpfs *** [ 0.029359] *** VALIDATE proc *** [ 0.031140] *** VALIDATE cgroup *** [ 0.032020] *** VALIDATE cgroup2 *** [ 0.033267] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034141] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035007] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.036028] Spectre V2 : User space: Vulnerable [ 0.037010] Speculative Store Bypass: Vulnerable [ 0.040135] debug: unmapping init [mem 0xffffffffb6459000-0xffffffffb6460fff] [ 0.042963] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044060] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045024] ... version: 2 [ 0.046015] ... bit width: 48 [ 0.047012] ... generic registers: 4 [ 0.048012] ... value mask: 0000ffffffffffff [ 0.049015] ... max period: 00007fffffffffff [ 0.050015] ... fixed-purpose events: 3 [ 0.051013] ... event mask: 000000070000000f [ 0.052314] rcu: Hierarchical SRCU implementation. [ 0.054342] smp: Bringing up secondary CPUs ... [ 0.055576] x86: Booting SMP configuration: [ 0.056030] .... node #0, CPUs: #1 #2 #3 [ 0.059223] smp: Brought up 1 node, 4 CPUs [ 0.061013] smpboot: Max logical packages: 1 [ 0.062018] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.133804] node 0 deferred pages initialised in 67ms [ 0.137122] devtmpfs: initialized [ 0.139254] x86/mm: Memory block size: 128MB [ 0.141778] gcov: version magic: 0x41383552 [ 0.145232] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.146081] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.147301] pinctrl core: initialized pinctrl subsystem [ 0.148215] [ 0.148786] ************************************************************* [ 0.149015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.150012] ** ** [ 0.151014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.152015] ** ** [ 0.153013] ** This means that this kernel is built to expose internal ** [ 0.154015] ** IOMMU data structures, which may compromise security on ** [ 0.155013] ** your system. ** [ 0.156011] ** ** [ 0.157013] ** If you see this message and you are not debugging the ** [ 0.158016] ** kernel, report this immediately to your vendor! ** [ 0.159013] ** ** [ 0.160016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.161015] ************************************************************* [ 0.162607] NET: Registered protocol family 16 [ 0.163459] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.164064] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.165065] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.167011] cpuidle: using governor menu [ 0.168467] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.171634] PCI: Using configuration type 1 for base access [ 0.174129] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.185079] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.187041] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.192073] cryptd: max_cpu_qlen set to 1000 [ 0.194242] ACPI: Added _OSI(Module Device) [ 0.196017] ACPI: Added _OSI(Processor Device) [ 0.198012] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.199010] ACPI: Added _OSI(Processor Aggregator Device) [ 0.203462] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.206322] ACPI: Interpreter enabled [ 0.207064] ACPI: PM: (supports S0 S3 S4 S5) [ 0.209014] ACPI: Using IOAPIC for interrupt routing [ 0.211092] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.214444] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.223746] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.225038] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.228021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.231078] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.236277] acpiphp: Slot [2] registered [ 0.237123] acpiphp: Slot [5] registered [ 0.239107] acpiphp: Slot [6] registered [ 0.240103] acpiphp: Slot [7] registered [ 0.242152] acpiphp: Slot [8] registered [ 0.243114] acpiphp: Slot [9] registered [ 0.244109] acpiphp: Slot [10] registered [ 0.246121] acpiphp: Slot [3] registered [ 0.248097] acpiphp: Slot [4] registered [ 0.249095] acpiphp: Slot [11] registered [ 0.251125] acpiphp: Slot [12] registered [ 0.253114] acpiphp: Slot [13] registered [ 0.254112] acpiphp: Slot [14] registered [ 0.256136] acpiphp: Slot [15] registered [ 0.258085] acpiphp: Slot [16] registered [ 0.259107] acpiphp: Slot [17] registered [ 0.261127] acpiphp: Slot [18] registered [ 0.262139] acpiphp: Slot [19] registered [ 0.264121] acpiphp: Slot [20] registered [ 0.265090] acpiphp: Slot [21] registered [ 0.267114] acpiphp: Slot [22] registered [ 0.268102] acpiphp: Slot [23] registered [ 0.270095] acpiphp: Slot [24] registered [ 0.271083] acpiphp: Slot [25] registered [ 0.272111] acpiphp: Slot [26] registered [ 0.274105] acpiphp: Slot [27] registered [ 0.275085] acpiphp: Slot [28] registered [ 0.277101] acpiphp: Slot [29] registered [ 0.278104] acpiphp: Slot [30] registered [ 0.280103] acpiphp: Slot [31] registered [ 0.282095] PCI host bridge to bus 0000:00 [ 0.284023] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.286025] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.288020] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.291031] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.293042] pci_bus 0000:00: root bus resource [mem 0x380000000000-0x38007fffffff window] [ 0.296029] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.298171] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.300979] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.304211] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.313014] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.317074] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.320019] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.323023] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.325015] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.327361] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.330803] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.333047] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.336690] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.341014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.354896] pci 0000:00:02.0: reg 0x20: [mem 0x380000000000-0x380000003fff 64bit pref] [ 0.359917] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.366254] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.373033] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.379021] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.393038] pci 0000:00:05.0: reg 0x20: [mem 0x380000004000-0x380000007fff 64bit pref] [ 0.405407] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.411018] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.417019] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.432020] pci 0000:00:06.0: reg 0x20: [mem 0x380000008000-0x38000000bfff 64bit pref] [ 0.442934] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.449022] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.454026] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.468069] pci 0000:00:07.0: reg 0x20: [mem 0x38000000c000-0x38000000ffff 64bit pref] [ 0.481858] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.489016] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.496016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.514022] pci 0000:00:08.0: reg 0x20: [mem 0x380000010000-0x380000013fff 64bit pref] [ 0.525332] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.531017] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.538016] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.554021] pci 0000:00:09.0: reg 0x20: [mem 0x380000014000-0x380000017fff 64bit pref] [ 0.564979] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.570018] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.577025] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.591028] pci 0000:00:0a.0: reg 0x20: [mem 0x380000018000-0x38000001bfff 64bit pref] [ 0.602000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.605475] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.607324] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.609407] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.611235] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.618057] iommu: Default domain type: Passthrough [ 0.620473] SCSI subsystem initialized [ 0.621117] ACPI: bus type USB registered [ 0.623118] usbcore: registered new interface driver usbfs [ 0.624072] usbcore: registered new interface driver hub [ 0.626089] usbcore: registered new device driver usb [ 0.628200] pps_core: LinuxPPS API ver. 1 registered [ 0.630013] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.633067] PTP clock support registered [ 0.634209] EDAC MC: Ver: 3.0.0 [ 0.636191] PCI: Using ACPI for IRQ routing [ 0.639168] NetLabel: Initializing [ 0.640010] NetLabel: domain hash size = 128 [ 0.642015] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.644108] NetLabel: unlabeled traffic allowed by default [ 0.646210] vgaarb: loaded [ 0.647293] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.649020] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.655366] clocksource: Switched to clocksource kvm-clock [ 0.760776] VFS: Disk quotas dquot_6.6.0 [ 0.762224] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.765628] *** VALIDATE ramfs *** [ 0.767038] *** VALIDATE hugetlbfs *** [ 0.768427] pnp: PnP ACPI init [ 0.770816] pnp: PnP ACPI: found 6 devices [ 0.789319] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.792536] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.794737] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.797068] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.799428] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.801967] pci_bus 0000:00: resource 8 [mem 0x380000000000-0x38007fffffff window] [ 0.804721] NET: Registered protocol family 2 [ 0.806988] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.811815] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.814947] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.821435] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.825298] TCP: Hash tables configured (established 65536 bind 65536) [ 0.828565] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.832304] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.835333] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.838803] NET: Registered protocol family 1 [ 0.841582] RPC: Registered named UNIX socket transport module. [ 0.844126] RPC: Registered udp transport module. [ 0.845895] RPC: Registered tcp transport module. [ 0.847710] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.850292] NET: Registered protocol family 44 [ 0.852304] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.854791] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.856960] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.859449] PCI: CLS 0 bytes, default 64 [ 0.861396] Unpacking initramfs... [ 2.320373] debug: unmapping init [mem 0xffff9cdbbcc54000-0xffff9cdbbffbffff] [ 2.327328] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.329360] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.332870] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.828365] Initialise system trusted keyrings [ 2.829996] Key type blacklist registered [ 2.832199] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.840499] zbud: loaded [ 2.843417] *** VALIDATE nfs *** [ 2.844633] *** VALIDATE nfs4 *** [ 2.846191] pstore: using deflate compression [ 2.850686] Platform Keyring initialized [ 2.968987] NET: Registered protocol family 38 [ 2.970918] Key type asymmetric registered [ 2.972248] Asymmetric key parser 'x509' registered [ 2.973996] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.977380] io scheduler mq-deadline registered [ 2.978973] io scheduler kyber registered [ 2.980687] io scheduler bfq registered [ 2.982411] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.984747] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.987016] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.989439] ACPI: Power Button [PWRF] [ 3.083200] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.175320] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.371405] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.468756] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.665979] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.695864] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.724845] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.731836] Non-volatile memory driver v1.3 [ 3.733672] Linux agpgart interface v0.103 [ 3.770244] virtio_blk virtio1: [vda] 133016 512-byte logical blocks (68.1 MB/64.9 MiB) [ 3.772950] vda: detected capacity change from 0 to 68104192 [ 3.788865] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.791864] vdb: detected capacity change from 0 to 1073741824 [ 3.808146] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.811351] vdc: detected capacity change from 0 to 2621440000 [ 3.825685] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.828709] vdd: detected capacity change from 0 to 2621440000 [ 3.843312] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.846674] vde: detected capacity change from 0 to 4294967296 [ 3.862598] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.865325] vdf: detected capacity change from 0 to 4294967296 [ 3.871336] libphy: Fixed MDIO Bus: probed [ 3.876103] usbcore: registered new interface driver usbserial_generic [ 3.878386] usbserial: USB Serial support registered for generic [ 3.880708] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.886030] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.887661] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.889681] mousedev: PS/2 mouse device common for all mice [ 3.892285] rtc_cmos 00:05: RTC can wake from S4 [ 3.895491] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.896579] rtc_cmos 00:05: registered as rtc0 [ 3.901330] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.903607] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.904521] intel_pstate: CPU model not supported [ 3.908700] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.913295] hid: raw HID events driver (C) Jiri Kosina [ 3.915597] usbcore: registered new interface driver usbhid [ 3.917720] usbhid: USB HID core driver [ 3.919300] drop_monitor: Initializing network drop monitor service [ 3.921402] Initializing XFRM netlink socket [ 3.923232] NET: Registered protocol family 10 [ 3.925840] Segment Routing with IPv6 [ 3.927199] NET: Registered protocol family 17 [ 3.929229] mpls_gso: MPLS GSO support [ 3.933671] RAS: Correctable Errors collector initialized. [ 3.936071] AVX version of gcm_enc/dec engaged. [ 3.937883] AES CTR mode by8 optimization enabled [ 4.028266] sched_clock: Marking stable (4028239252, 0)->(4955984622, -927745370) [ 4.031276] registered taskstats version 1 [ 4.033874] Loading compiled-in X.509 certificates [ 4.036069] zswap: loaded using pool lzo/zbud [ 4.061194] Key type big_key registered [ 4.073702] Key type encrypted registered [ 4.075249] ima: No TPM chip found, activating TPM-bypass! [ 4.077475] ima: Allocated hash algorithm: sha1 [ 4.079617] ima: No architecture policies found [ 4.081617] evm: Initialising EVM extended attributes: [ 4.083562] evm: security.selinux [ 4.084657] evm: security.ima [ 4.085650] evm: security.capability [ 4.086823] evm: HMAC attrs: 0x1 [ 4.094560] rtc_cmos 00:05: setting system clock to 2025-08-05 14:54:09 UTC (1754405649) [ 4.101876] debug: unmapping init [mem 0xffffffffb7403000-0xffffffffb75fffff] [ 4.110837] debug: unmapping init [mem 0xffffffffb6182000-0xffffffffb6458fff] [ 4.123141] Write protecting the kernel read-only data: 28672k [ 4.126496] debug: unmapping init [mem 0xffffffffb4803000-0xffffffffb49fffff] [ 4.128936] debug: unmapping init [mem 0xffffffffb5114000-0xffffffffb51fffff] [ 4.169750] 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) [ 4.177679] systemd[1]: Detected virtualization kvm. [ 4.180243] systemd[1]: Detected architecture x86-64. [ 4.182211] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.207579] systemd[1]: No hostname configured. [ 4.209462] systemd[1]: Set hostname to . [ 4.211726] random: systemd: uninitialized urandom read (16 bytes read) [ 4.214270] systemd[1]: Initializing machine ID from random generator. [ 4.263841] random: ln: uninitialized urandom read (6 bytes read) [ 4.372971] random: systemd: uninitialized urandom read (16 bytes read) [ 4.375786] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 4.380295] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 4.386389] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Swap. [ OK ] Reached target Timers. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on udev Kernel Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Journal Socket. [ OK ] Reached target Sockets. [ OK ] Started Memstrack Anylazing Service. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... Starting Create Volatile Files and Directories... [ OK ] Reached target Slices. Starting Setup Virtual Console... Starting Journal Service... [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 5.024644] device-mapper: uevent: version 1.0.3 [ 5.026612] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.763292] virtio_net virtio0 ens2: renamed from eth0 [ 5.786490] random: fast init done [ 5.794493] scsi host0: ata_piix [ 5.815455] scsi host1: ata_piix [ 5.816830] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.820067] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.704605] dracut-initqueue[589]: RTNETLINK answers: File exists [ 10.597144] random: crng init done [ 10.599622] 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... [ 11.161718] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Slices. [ 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... [ 12.343495] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.609444] SELinux: Disabled at runtime. [ 12.664783] 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.672943] systemd[1]: Detected virtualization kvm. [ 12.674812] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 13.168667] systemd[1]: initrd-switch-root.service: Succeeded. [ 13.172512] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 13.177424] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 13.181255] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 13.184572] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 13.194024] systemd[1]: Starting Journal Service... Starting Journal Service... [ 13.204582] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting Huge Pages File System... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Created slice system-getty.slice. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting Kernel Debug File System... Mounting POSIX Message Queue File System... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on udev Kernel Socket. Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. Starting Apply Kernel Variables... [ OK ] Reached target rpc_pipefs.target. [ 13.343738] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started udev Coldplug all Devices. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 13.658890] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.933236] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.966305] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 14.068472] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 14.083723] EDAC sbridge: Ver: 1.1.2 [ 15.810415] Key type dns_resolver registered [ 16.115168] NFS: Registering the id_resolver key type [ 16.117318] Key type id_resolver registered [ 16.118833] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. [ OK ] Started D-Bus System Message Bus. Starting Restore /run/initramfs on shutdown... [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. Starting Network Manager... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ 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 oleg133-server login: [ 41.017127] libcfs: loading out-of-tree module taints kernel. [ 41.028185] Key type ._llcrypt registered [ 41.029905] Key type .llcrypt registered [ 41.079308] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_hostid [ 54.019820] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 55.148857] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 55.161771] alg: No test for adler32 (adler32-zlib) [ 56.338267] Lustre: Lustre: Build Version: 2.16.57_28_g7ecc534 [ 56.853340] LNet: Added LNI 192.168.201.133@tcp [8/256/0/180] [ 58.529633] Key type lgssc registered [ 59.803453] Lustre: Echo OBD driver; http://www.lustre.org/ [ 73.331989] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 76.382762] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 84.054009] hrtimer: interrupt took 6998599 ns [ 84.660451] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 90.522977] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 96.319165] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 108.902976] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 118.718582] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 118.768191] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 118.787465] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 119.966212] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 119.997806] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 120.064764] Lustre: lustre-MDT0000: new disk, initializing [ 120.133505] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 120.154197] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 122.846291] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 132.933452] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 132.995190] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 133.051949] Lustre: 6495:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 133.085393] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 133.088325] Lustre: Skipped 1 previous similar message [ 133.140196] Lustre: lustre-MDT0001: new disk, initializing [ 133.211055] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 133.236317] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 133.245800] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 135.619756] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 138.955033] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 146.451731] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 146.508765] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 146.653782] Lustre: lustre-OST0000: new disk, initializing [ 146.658898] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 146.716828] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 151.143783] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 154.118974] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 154.129165] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 154.155606] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 161.181519] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 161.232881] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 161.297600] Lustre: lustre-OST0001: new disk, initializing [ 161.299900] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 161.365132] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 164.962315] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 168.443200] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 168.448198] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 168.476053] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 173.197970] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 179.510378] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 187.996106] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing check_logdir /tmp/testlogs/ [ 190.621448] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing yml_node [ 193.533481] Lustre: DEBUG MARKER: Client: 2.16.57.28 [ 194.984512] Lustre: DEBUG MARKER: MDS: 2.16.57.28 [ 196.709772] Lustre: DEBUG MARKER: OSS: 2.16.57.28 [ 197.751914] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Tue Aug 5 10:57:21 EDT 2025 [ 209.775269] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 216.225237] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 224.739181] 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 [ 224.742063] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 224.745235] Lustre: Skipped 3 previous similar messages [ 224.748163] Lustre: Skipped 2 previous similar messages [ 227.678730] LustreError: 12515:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 227.741826] Lustre: server umount lustre-MDT0000 complete [ 233.579416] LustreError: 6487:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754405878 with bad export cookie 6540963649230950520 [ 233.581501] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 233.586984] LustreError: 6487:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 233.762647] LustreError: 12965:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 233.767052] LustreError: 12965:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 233.989940] Lustre: server umount lustre-MDT0001 complete [ 250.297068] LustreError: 13415:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 250.303731] LustreError: 13415:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 250.345290] Lustre: server umount lustre-OST0000 complete [ 251.359110] Lustre: 3648:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1754405880/real 1754405880] req@ffff9cdb04bb7100 x1839627713467136/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1754405896 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 251.375891] 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 [ 255.459916] Lustre: 3646:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1754405884/real 1754405884] req@ffff9cdc10b70000 x1839627713467392/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1754405900 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 256.174940] LustreError: 13866:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 256.178729] LustreError: 13866:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 256.310612] Lustre: server umount lustre-OST0001 complete [ 265.203888] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing unload_modules_local [ 267.120492] Key type lgssc unregistered [ 267.307852] LNet: 14641:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 267.311280] LNetError: 14641:0:(acceptor.c:254:lnet_acceptor_remove_socket()) Interface ens2 not found [ 267.319825] LNet: Removed LNI 192.168.201.133@tcp [ 267.942712] Key type .llcrypt unregistered [ 267.946798] Key type ._llcrypt unregistered [ 280.836593] Key type ._llcrypt registered [ 280.841989] Key type .llcrypt registered [ 280.918735] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_hostid [ 288.931370] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 289.724678] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 289.766381] alg: No test for adler32 (adler32-zlib) [ 290.696482] Lustre: Lustre: Build Version: 2.16.57_28_g7ecc534 [ 290.827286] LNet: Added LNI 192.168.201.133@tcp [8/256/0/180] [ 292.471479] Key type lgssc registered [ 293.225427] Lustre: Echo OBD driver; http://www.lustre.org/ [ 299.192102] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 303.316705] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 306.431493] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 309.989858] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 316.775537] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 322.907925] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 322.931598] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 322.939488] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 324.070925] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 324.090842] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 324.132420] Lustre: lustre-MDT0000: new disk, initializing [ 324.169815] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 324.183054] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 325.958974] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 333.360471] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 333.403785] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 333.449416] Lustre: 19003:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 333.470166] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 333.472953] Lustre: Skipped 1 previous similar message [ 333.513296] Lustre: lustre-MDT0001: new disk, initializing [ 333.550664] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 333.569947] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 333.577086] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 335.289364] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 338.008174] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 342.724603] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 342.766418] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 342.922202] Lustre: lustre-OST0000: new disk, initializing [ 342.924615] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 342.970494] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 346.446553] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 346.453989] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 346.533837] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 346.985639] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 355.877070] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 355.923284] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 355.988547] Lustre: lustre-OST0001: new disk, initializing [ 355.993378] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 356.029665] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 359.502568] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 366.092904] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 366.099746] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 366.144274] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 367.382363] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 372.458562] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 381.545507] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 11:00:25 (1754406025) === [ 383.211565] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 11:00:27 (1754406027) [ 388.357984] Lustre: 20890:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 388.373950] Lustre: 20890:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 388.376381] Lustre: 23150:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 388.382517] Lustre: 20890:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 1 previous similar message [ 388.392639] Lustre: 23150:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 388.392654] Lustre: 23150:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 388.392661] Lustre: 23150:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 388.444910] LustreError: 23159:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 3000ms [ 391.474060] LustreError: 23159:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 awake [ 392.656489] LustreError: 23402:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 3000ms [ 393.477937] Lustre: 23156:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 393.482944] Lustre: 23472:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 393.491590] Lustre: 23156:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 10 previous similar messages [ 393.492929] Lustre: 23472:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 7 previous similar messages [ 393.498279] Lustre: 23156:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 393.502313] Lustre: 23472:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 393.505490] Lustre: 23156:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 10 previous similar messages [ 393.509492] Lustre: 23472:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 393.509524] Lustre: 23472:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 393.509528] Lustre: 23472:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 393.509534] Lustre: 23472:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 393.509537] Lustre: 23472:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 393.919074] LustreError: 23402:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout interrupted [ 400.352042] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 400.356038] 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 [ 400.378571] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 401.887467] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 401.892498] 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 [ 401.900801] Lustre: Skipped 2 previous similar messages [ 405.069341] LustreError: 23898:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 407.139182] LustreError: 23898:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 407.143898] LustreError: 23898:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 407.182073] Lustre: server umount lustre-MDT0000 complete [ 409.244897] LustreError: 19940:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754406054 with bad export cookie 10444330564655752763 [ 409.246968] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 409.253229] LustreError: 19940:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 409.335153] LustreError: 24100:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 409.337584] LustreError: 24100:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 409.457127] Lustre: server umount lustre-MDT0001 complete [ 421.381400] LustreError: 24300:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 421.388958] LustreError: 24300:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 421.424678] Lustre: server umount lustre-OST0000 complete [ 434.231196] LustreError: 24515:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 434.235423] LustreError: 24515:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 434.396349] Lustre: server umount lustre-OST0001 complete [ 438.681973] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 11:01:22 (1754406082) [ 445.808566] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 451.429257] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 451.672279] LustreError: 25877:0:(ldlm_lib.c:1113: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. [ 451.685903] LustreError: 25877:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 5 previous similar messages [ 451.728630] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 454.113059] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 457.184505] LustreError: 25877:0:(ldlm_lib.c:1113: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. [ 458.959386] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 461.396080] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 462.970491] Lustre: 26972:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 466.670859] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 466.832910] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 466.835700] Lustre: Skipped 1 previous similar message [ 468.899304] LustreError: 27327:0:(ldlm_lib.c:1113: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. [ 469.904218] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 474.079787] LustreError: 27529:0:(ldlm_lib.c:1113: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. [ 475.093810] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 477.419406] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 477.420923] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 478.645359] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 483.488688] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 485.397580] Lustre: 28803:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 494.576387] Lustre: *** cfs_fail_loc=1501, val=0*** [ 494.604653] Lustre: 27328:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 494.609946] Lustre: 27328:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 65 previous similar messages [ 494.613460] Lustre: 27328:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 494.618595] Lustre: 27328:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 494.622924] Lustre: 27328:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 494.627509] Lustre: 27328:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 494.631800] Lustre: 27328:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 494.638207] Lustre: 27328:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 494.643073] Lustre: 27328:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 494.646668] Lustre: 27328:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 494.651097] Lustre: 27328:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 494.654761] Lustre: 27328:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 499.183671] Lustre: Failing over lustre-MDT0000 [ 499.298788] LustreError: 29175:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 499.302603] LustreError: 29175:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 499.359762] Lustre: server umount lustre-MDT0000 complete [ 500.196121] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 500.203560] 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 [ 500.214260] LustreError: 26897:0:(ldlm_lib.c:1113: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. [ 503.265108] 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 [ 503.276311] Lustre: Skipped 2 previous similar messages [ 505.865549] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 505.919344] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 506.057897] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 506.062145] Lustre: Skipped 1 previous similar message [ 508.327543] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 509.459783] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 509.468364] Lustre: lustre-MDT0000: Denying connection for new client eae5414a-d5bc-4aa5-8d80-d682203d8be9 (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 511.460842] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 511.472102] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 511.492437] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 511.495770] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 515.554853] Lustre: *** cfs_fail_loc=1505, val=0*** [ 519.877560] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 11:02:43 (1754406163) [ 520.963480] Lustre: 28937:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 520.975457] Lustre: 28937:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 77 previous similar messages [ 520.979515] Lustre: 28937:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 520.983975] Lustre: 28937:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 520.989930] Lustre: 28937:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 520.994945] Lustre: 28937:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 520.999897] Lustre: 28937:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 521.006539] Lustre: 28937:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 521.011750] Lustre: 28937:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 521.017740] Lustre: 28937:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 521.024410] Lustre: 28937:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 521.030382] Lustre: 28937:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 524.525948] Lustre: *** cfs_fail_loc=1502, val=0*** [ 525.787654] Lustre: 28937:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 525.788180] Lustre: 27332:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 525.801430] Lustre: 28937:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 2 previous similar messages [ 525.801458] Lustre: 28937:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 525.801462] Lustre: 28937:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 1 previous similar message [ 525.801468] Lustre: 28937:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 525.801471] Lustre: 28937:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 1 previous similar message [ 525.801479] Lustre: 28937:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 525.808160] Lustre: 27332:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 2 previous similar messages [ 525.808238] Lustre: 27332:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 525.808259] Lustre: 27332:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 1 previous similar message [ 525.870709] Lustre: 28937:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 529.893199] Lustre: Failing over lustre-MDT0000 [ 530.011745] LustreError: 30826:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 530.013948] LustreError: 30826:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 530.064642] Lustre: server umount lustre-MDT0000 complete [ 531.936522] 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 [ 531.936748] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 531.942674] LustreError: 28132:0:(ldlm_lib.c:1113: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. [ 531.942685] LustreError: 28132:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 4 previous similar messages [ 531.961229] Lustre: Skipped 3 previous similar messages [ 535.673155] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 535.744495] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 537.991532] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 539.239065] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 539.244143] Lustre: lustre-MDT0000: Denying connection for new client e0763131-de52-4bff-9e01-a4f7b6971c5b (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 541.157231] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 541.160049] Lustre: Skipped 3 previous similar messages [ 541.170663] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 541.193824] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 541.194026] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:170 to 0x280000401:193) [ 545.099092] Lustre: *** cfs_fail_loc=1505, val=0*** [ 548.817490] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 11:03:12 (1754406192) [ 552.672626] Lustre: *** cfs_fail_loc=1504, val=0*** [ 552.674815] Lustre: *** cfs_fail_loc=1504, val=0*** [ 552.676516] Lustre: Skipped 1 previous similar message [ 552.696316] Lustre: 28930:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 552.700701] Lustre: 28930:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 75 previous similar messages [ 552.704114] Lustre: 28930:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 552.709988] Lustre: 28930:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 75 previous similar messages [ 552.713791] Lustre: 28930:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 552.717345] Lustre: 28930:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 76 previous similar messages [ 552.721631] Lustre: 28930:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 552.725286] Lustre: 28930:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 76 previous similar messages [ 552.729059] Lustre: 28930:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 552.733716] Lustre: 28930:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 55 previous similar messages [ 552.738450] Lustre: 28930:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 552.741770] Lustre: 28930:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 76 previous similar messages [ 556.680123] Lustre: Failing over lustre-MDT0000 [ 556.792417] Lustre: server umount lustre-MDT0000 complete [ 561.631471] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 561.631876] 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 [ 561.638356] LustreError: 28132:0:(ldlm_lib.c:1113: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. [ 561.638368] LustreError: 28132:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 3 previous similar messages [ 561.664865] Lustre: Skipped 3 previous similar messages [ 562.411294] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 562.495362] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 562.646227] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 562.649652] Lustre: Skipped 1 previous similar message [ 564.768175] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 565.947419] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 565.951975] Lustre: lustre-MDT0000: Denying connection for new client 14739bd5-0f5a-4260-a3ff-1653b5ca1304 (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 567.779759] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to (at 0@lo) [ 567.782734] Lustre: Skipped 3 previous similar messages [ 567.791286] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 567.818297] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:234 to 0x280000401:257) [ 567.818906] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 571.604795] Lustre: *** cfs_fail_loc=1505, val=0*** [ 574.732804] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 11:03:38 (1754406218) [ 576.770250] Lustre: 30490:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 576.776668] Lustre: 30493:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 576.778544] Lustre: 30490:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 79 previous similar messages [ 576.783424] Lustre: 30493:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 576.783439] Lustre: 30493:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 576.783443] Lustre: 30493:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 576.783449] Lustre: 30493:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 576.783452] Lustre: 30493:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 576.783457] Lustre: 30493:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 576.783460] Lustre: 30493:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 576.783465] Lustre: 30493:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 576.783468] Lustre: 30493:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 578.005476] Lustre: *** cfs_fail_loc=1603, val=0*** [ 581.639352] Lustre: Failing over lustre-MDT0000 [ 581.723119] LustreError: 33923:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 581.726651] LustreError: 33923:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 581.766406] Lustre: server umount lustre-MDT0000 complete [ 583.139325] 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 [ 583.139711] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 583.145286] Lustre: Skipped 2 previous similar messages [ 587.777417] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 587.844758] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 590.185430] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 591.405475] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 591.409215] Lustre: lustre-MDT0000: Denying connection for new client 0c109b2a-7f76-4f2e-a04d-3bb95ed6a402 (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 593.381932] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 593.384120] Lustre: Skipped 3 previous similar messages [ 593.398973] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 593.417391] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:298 to 0x280000401:321) [ 593.418385] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 600.017606] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 11:04:04 (1754406244) [ 603.767763] Lustre: *** cfs_fail_loc=1604, val=0*** [ 607.777844] Lustre: Failing over lustre-MDT0000 [ 607.902120] Lustre: server umount lustre-MDT0000 complete [ 608.735713] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 608.739254] LustreError: 25870:0:(ldlm_lib.c:1113: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. [ 608.748734] LustreError: 25870:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 10 previous similar messages [ 614.063787] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 614.143634] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 614.283369] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 616.292959] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 617.369971] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 617.374810] Lustre: lustre-MDT0000: Denying connection for new client 365e08c5-d5b2-4781-a530-025824ccb018 (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 619.490469] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 619.492946] Lustre: Skipped 3 previous similar messages [ 619.498542] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 619.518309] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 619.522884] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:362 to 0x280000401:385) [ 626.253440] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 11:04:30 (1754406270) [ 630.817763] Lustre: *** cfs_fail_loc=1605, val=0*** [ 630.833518] Lustre: 28925:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 630.838719] Lustre: 28925:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 148 previous similar messages [ 630.844336] Lustre: 28925:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 630.849230] Lustre: 28925:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 630.853800] Lustre: 28925:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 630.857575] Lustre: 28925:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 630.862256] Lustre: 28925:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 630.866018] Lustre: 28925:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 630.871095] Lustre: 28925:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 630.875608] Lustre: 28925:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 630.880267] Lustre: 28925:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 630.884551] Lustre: 28925:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 634.269743] Lustre: Failing over lustre-MDT0000 [ 634.400626] Lustre: server umount lustre-MDT0000 complete [ 634.847460] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 634.848509] 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 [ 634.860839] Lustre: Skipped 8 previous similar messages [ 639.761868] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 639.830855] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 639.977959] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 639.981732] Lustre: Skipped 2 previous similar messages [ 640.003054] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 641.943240] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 643.042500] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 643.046635] Lustre: lustre-MDT0000: Denying connection for new client eb0ceb11-abb7-4e1f-b11d-16b5c3510d44 (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 645.093015] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to (at 0@lo) [ 645.095661] Lustre: Skipped 3 previous similar messages [ 645.104856] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 645.132358] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 645.132368] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:426 to 0x2c0000401:449) [ 651.565537] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 11:04:55 (1754406295) [ 654.695992] Lustre: *** cfs_fail_loc=161d, val=0*** [ 657.850464] Lustre: Failing over lustre-MDT0000 [ 657.931305] LustreError: 38276:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 657.934141] LustreError: 38276:0:(obd_class.h:479:obd_check_dev()) Skipped 23 previous similar messages [ 657.972480] Lustre: server umount lustre-MDT0000 complete [ 662.669088] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 662.855955] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 664.497426] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 665.439269] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 665.443517] Lustre: lustre-MDT0000: Denying connection for new client d5cf06b0-d6dd-4866-b84e-ff66cc7de6d4 (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 668.129799] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 668.132373] Lustre: Skipped 3 previous similar messages [ 668.138190] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 668.164222] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:490 to 0x2c0000401:513) [ 668.164566] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 673.244318] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 11:05:17 (1754406317) [ 674.282692] Lustre: *** cfs_fail_loc=1603, val=0*** [ 678.679989] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 11:05:22 (1754406322) [ 681.308962] Lustre: *** cfs_fail_loc=1603, val=0*** [ 681.778404] Lustre: *** cfs_fail_loc=1604, val=0*** [ 686.390846] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 11:05:30 (1754406330) [ 717.818958] Lustre: 27332:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 717.819594] Lustre: 28939:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 717.827344] Lustre: 27332:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 202 previous similar messages [ 717.831475] Lustre: 28939:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 201 previous similar messages [ 717.835486] Lustre: 27332:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 717.835493] Lustre: 27332:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 201 previous similar messages [ 717.835499] Lustre: 27332:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 717.835502] Lustre: 27332:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 201 previous similar messages [ 717.839085] Lustre: 28939:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 717.843157] Lustre: 27332:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 717.846754] Lustre: 28939:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 202 previous similar messages [ 717.882475] Lustre: 27332:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 231 previous similar messages [ 719.216415] Lustre: Failing over lustre-MDT0000 [ 719.330100] 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 [ 719.330484] LustreError: 39537:0:(ldlm_lib.c:1113: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. [ 719.332112] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 719.332119] LustreError: Skipped 1 previous similar message [ 719.335323] Lustre: Skipped 7 previous similar messages [ 719.352016] LustreError: 39537:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 15 previous similar messages [ 719.392346] Lustre: server umount lustre-MDT0000 complete [ 721.938790] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 726.354435] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 726.823100] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 732.419597] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 732.434736] Lustre: lustre-MDT0000: reset Object Index mappings [ 732.487153] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 732.491900] LustreError: Skipped 1 previous similar message [ 732.652202] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 734.383911] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 736.150581] LustreError: 42249:0:(lfsck_engine.c:1045:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 736.161347] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 737.215409] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 737.760850] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 737.763783] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 737.774139] Lustre: Skipped 3 previous similar messages [ 737.787767] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 737.809275] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:593 to 0x2c0000401:609) [ 737.810066] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:593 to 0x280000401:609) [ 738.271129] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 738.274812] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 738.278424] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 1 previous similar message [ 740.375186] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 740.380189] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 1 previous similar message [ 740.704160] LustreError: 42249:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout interrupted [ 742.784876] Lustre: Failing over lustre-MDT0000 [ 742.887186] Lustre: server umount lustre-MDT0000 complete [ 747.600582] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 747.809560] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 749.441833] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 750.562905] Lustre: lustre-MDT0000: Denying connection for new client c03cb69b-e75e-470d-808e-aa7618651b09 (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 753.148771] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:593 to 0x2c0000401:641) [ 753.150341] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:593 to 0x280000401:641) [ 756.444054] Lustre: *** cfs_fail_loc=1505, val=0*** [ 759.613631] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 11:06:43 (1754406403) [ 760.777741] Lustre: *** cfs_fail_loc=1504, val=0*** [ 764.085390] Lustre: Failing over lustre-MDT0000 [ 764.185410] Lustre: server umount lustre-MDT0000 complete [ 766.462305] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 770.299270] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 770.733061] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 775.590558] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 775.599676] Lustre: lustre-MDT0000: reset Object Index mappings [ 775.778660] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 775.781910] Lustre: Skipped 3 previous similar messages [ 775.823271] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 777.343739] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 778.790553] LustreError: 45946:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 778.794215] LustreError: 45946:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 2 previous similar messages [ 779.839160] LustreError: 45946:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 781.303197] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:682 to 0x280000401:705) [ 781.303280] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 785.351090] LustreError: 45946:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout interrupted [ 787.295548] Lustre: Failing over lustre-MDT0000 [ 787.368323] LustreError: 46540:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 787.370951] LustreError: 46540:0:(obd_class.h:479:obd_check_dev()) Skipped 31 previous similar messages [ 787.404424] Lustre: server umount lustre-MDT0000 complete [ 791.521877] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 791.525465] LustreError: Skipped 2 previous similar messages [ 791.990058] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 792.205296] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 793.993324] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 797.685696] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:682 to 0x280000401:737) [ 797.685802] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 800.944365] Lustre: *** cfs_fail_loc=1505, val=0*** [ 800.946360] Lustre: Skipped 85 previous similar messages [ 803.945259] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 11:07:28 (1754406448) [ 806.912063] LustreError: 47841:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 1000ms [ 806.918746] LustreError: 47841:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) Skipped 6 previous similar messages [ 807.959195] LustreError: 47841:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 awake [ 807.962430] LustreError: 47841:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) Skipped 5 previous similar messages [ 811.087176] Lustre: *** cfs_fail_loc=1608, val=1*** [ 814.679322] LustreError: 48185:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout interrupted [ 817.604661] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 11:07:41 (1754406461) [ 823.255561] LustreError: 48674:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 823.261106] LustreError: 48674:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 7 previous similar messages [ 824.303173] LustreError: 48674:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 824.306549] LustreError: 48674:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 6 previous similar messages [ 827.431164] Lustre: *** cfs_fail_loc=1609, val=1*** [ 832.000061] LustreError: 49067:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout interrupted [ 834.758392] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 11:07:58 (1754406478) [ 842.596064] Lustre: Failing over lustre-MDT0000 [ 843.759416] Lustre: server umount lustre-MDT0000 complete [ 847.678603] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 847.739622] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 847.744368] LustreError: Skipped 3 previous similar messages [ 847.852229] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 849.344750] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 852.961703] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 852.962894] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 852.964856] Lustre: Skipped 3 previous similar messages [ 852.967324] Lustre: Skipped 15 previous similar messages [ 852.974782] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 852.977843] Lustre: Skipped 3 previous similar messages [ 852.995946] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:855 to 0x2c0000401:897) [ 852.995958] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:855 to 0x280000401:897) [ 855.459378] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 11:08:19 (1754406499) [ 860.535859] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 868.105370] Lustre: 52435:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 877.711868] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 879.127574] Lustre: 53568:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 888.315805] Lustre: *** cfs_fail_loc=1604, val=0*** [ 888.317988] Lustre: Skipped 82 previous similar messages [ 888.334777] Lustre: 28924:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 888.339473] Lustre: 28924:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 311 previous similar messages [ 888.345778] Lustre: 28924:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 888.349119] Lustre: 28924:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 311 previous similar messages [ 888.352628] Lustre: 28924:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 888.356503] Lustre: 28924:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 312 previous similar messages [ 888.360308] Lustre: 28924:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 888.366322] Lustre: 28924:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 311 previous similar messages [ 888.371028] Lustre: 28924:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 888.374995] Lustre: 28924:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 311 previous similar messages [ 888.379675] Lustre: 28924:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 888.384253] Lustre: 28924:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 277 previous similar messages [ 889.922554] LustreError: 53722:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout id 1602 sleeping for 1000ms [ 889.927971] LustreError: 53722:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 10 previous similar messages [ 890.975161] LustreError: 53722:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout id 1602 awake [ 890.981327] LustreError: 53722:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 9 previous similar messages [ 891.782277] Lustre: Failing over lustre-MDT0000 [ 893.209333] Lustre: server umount lustre-MDT0000 complete [ 893.920824] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 893.921223] LustreError: 30390:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 893.927879] Lustre: Skipped 17 previous similar messages [ 893.934697] LustreError: 30390:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 28 previous similar messages [ 897.610356] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 899.553433] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 903.156633] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:947 to 0x2c0000401:993) [ 903.156633] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 905.862026] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 11:09:10 (1754406550) [ 908.256190] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 908.258796] Lustre: Skipped 6 previous similar messages [ 912.797787] Lustre: server umount lustre-MDT0000 complete [ 914.127864] LustreError: 25857:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754406559 with bad export cookie 10444330564655969665 [ 914.132844] LustreError: 25857:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 914.271758] Lustre: server umount lustre-MDT0001 complete [ 925.702556] Lustre: server umount lustre-OST0000 complete [ 937.398617] Lustre: server umount lustre-OST0001 complete [ 939.713750] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_hostid [ 942.643028] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 946.527603] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 949.239891] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 951.685497] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 954.424425] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 960.019289] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 964.285018] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 964.310987] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 964.416362] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 964.432525] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 964.472199] Lustre: lustre-MDT0000: new disk, initializing [ 964.510475] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 966.004982] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 970.787336] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 970.817118] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 970.848861] Lustre: 58640:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 970.948351] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 972.599900] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 975.143099] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 977.875413] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 977.907948] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 977.993268] Lustre: lustre-OST0000: new disk, initializing [ 977.995483] Lustre: Skipped 1 previous similar message [ 977.997822] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 978.000793] Lustre: Skipped 2 previous similar messages [ 978.326498] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 978.329937] Lustre: Skipped 1 previous similar message [ 978.332117] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 978.367144] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 980.205938] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 984.627062] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 984.652823] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 986.541343] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 986.565492] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 986.766279] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 991.446325] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 992.786503] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1001.415667] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1001.794243] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1001.796128] Lustre: Skipped 19 previous similar messages [ 1003.003036] LustreError: 62087:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 2000ms [ 1003.008351] LustreError: 62087:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 2 previous similar messages [ 1005.095107] LustreError: 62087:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 1005.097914] LustreError: 62087:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 2 previous similar messages [ 1007.855191] Lustre: *** cfs_fail_loc=1609, val=2*** [ 1010.815147] Lustre: *** cfs_fail_loc=160a, val=2*** [ 1015.032800] Lustre: Failing over lustre-MDT0000 [ 1015.131667] Lustre: server umount lustre-MDT0000 complete [ 1017.312367] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1017.316162] LustreError: Skipped 3 previous similar messages [ 1018.659264] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1018.721965] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1018.726798] LustreError: Skipped 2 previous similar messages [ 1018.842251] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1018.845342] Lustre: Skipped 1 previous similar message [ 1020.238109] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1023.392506] Lustre: Failing over lustre-MDT0000 [ 1023.967632] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1023.972249] Lustre: Skipped 3 previous similar messages [ 1024.419962] LustreError: 63977:0:(ldlm_lib.c:2916:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 1024.423411] Lustre: 63303:0:(ldlm_lib.c:2319:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 1024.427619] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 1024.434781] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 1024.439799] LustreError: 63303:0:(client.c:1375:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff9cdc37ca6a00 x1839627959886720/t0(0) o700->lustre-MDT0001-osp-MDT0000@0@lo:30/10 lens 264/248 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'tgt_recover_0.0' uid:0 gid:0 projid:4294967295 [ 1024.448852] LustreError: 63303:0:(fid_request.c:213:seq_client_alloc_seq()) cli-cli-lustre-MDT0001-osp-MDT0000: Cannot allocate new meta-sequence: rc = -5 [ 1024.452352] LustreError: 63303:0:(fid_request.c:316:seq_client_alloc_fid()) cli-cli-lustre-MDT0001-osp-MDT0000: Can't allocate new sequence: rc = -5 [ 1024.568364] Lustre: server umount lustre-MDT0000 complete [ 1028.181833] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1029.851869] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1032.132644] Lustre: Failing over lustre-MDT0000 [ 1032.137864] LustreError: 65034:0:(ldlm_lib.c:2916:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 1032.141580] Lustre: 64508:0:(ldlm_lib.c:2319:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 1032.145310] Lustre: 64508:0:(ldlm_lib.c:2319:target_recovery_overseer()) Skipped 2 previous similar messages [ 1032.149128] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000bd0:0x1:0x0] [ 1032.158462] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 1032.164194] LustreError: 64508:0:(client.c:1375:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff9cdb0407c000 x1839627959897984/t0(0) o700->lustre-MDT0001-osp-MDT0000@0@lo:30/10 lens 264/248 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'tgt_recover_0.0' uid:0 gid:0 projid:4294967295 [ 1032.172368] LustreError: 64508:0:(fid_request.c:213:seq_client_alloc_seq()) cli-cli-lustre-MDT0001-osp-MDT0000: Cannot allocate new meta-sequence: rc = -5 [ 1032.176330] LustreError: 64508:0:(fid_request.c:316:seq_client_alloc_fid()) cli-cli-lustre-MDT0001-osp-MDT0000: Can't allocate new sequence: rc = -5 [ 1032.194308] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1032.293878] Lustre: server umount lustre-MDT0000 complete [ 1035.658277] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1035.769673] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1035.772902] Lustre: Skipped 9 previous similar messages [ 1037.109551] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1040.095078] LustreError: 66044:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout interrupted [ 1040.863632] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1040.865286] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 1040.866985] Lustre: Skipped 1 previous similar message [ 1040.869297] Lustre: Skipped 7 previous similar messages [ 1040.874745] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1040.877268] Lustre: Skipped 1 previous similar message [ 1040.890647] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:44 to 0x2c0000401:65) [ 1040.890649] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1042.973397] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 11:11:27 (1754406687) [ 1047.428220] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1053.353597] Lustre: 67913:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1061.506394] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1115.419939] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 11:12:39 (1754406759) [ 1130.735368] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1130.736707] Lustre: Skipped 4 previous similar messages [ 1135.948108] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1135.949582] Lustre: Skipped 1 previous similar message [ 1161.151670] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 11:13:25 (1754406805) [ 1171.670092] Lustre: 69161:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 1171.673499] Lustre: 69161:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 258 previous similar messages [ 1171.676243] Lustre: 69161:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1171.679068] Lustre: 69161:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 258 previous similar messages [ 1171.681461] Lustre: 69161:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 1171.683494] Lustre: 69161:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 258 previous similar messages [ 1171.685933] Lustre: 69161:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 1171.688045] Lustre: 69161:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 258 previous similar messages [ 1171.690663] Lustre: 69161:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1171.693339] Lustre: 69161:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 258 previous similar messages [ 1171.695690] Lustre: 69161:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1171.697383] Lustre: 69161:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 258 previous similar messages [ 1171.713251] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1179.717038] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1179.718556] Lustre: Skipped 1764 previous similar messages [ 1257.838885] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 11:15:02 (1754406902) [ 1301.985748] 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 [ 1301.986157] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1301.986788] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1301.991800] Lustre: Skipped 13 previous similar messages [ 1304.518442] LustreError: 71925:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 1304.520469] LustreError: 71925:0:(obd_class.h:479:obd_check_dev()) Skipped 73 previous similar messages [ 1304.563096] Lustre: server umount lustre-MDT0000 complete [ 1305.865629] LustreError: 58633:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754406951 with bad export cookie 10444330564655988194 [ 1305.866334] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1305.871057] LustreError: 58633:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1305.878165] LustreError: Skipped 2 previous similar messages [ 1306.026712] Lustre: server umount lustre-MDT0001 complete [ 1317.578361] Lustre: server umount lustre-OST0000 complete [ 1329.340881] Lustre: server umount lustre-OST0001 complete [ 1331.976773] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 1335.368943] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1352.863282] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 1359.007233] LustreError: 73324:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.133@tcp: failed processing log, type 4: rc = -110 [ 1390.566866] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1391.754433] Lustre: 73885:0:(ofd_dev.c:560:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1391.762066] Lustre: *** cfs_fail_loc=160e, val=3*** [ 1394.785312] Lustre: 73885:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1397.980498] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 11:17:22 (1754407042) [ 1402.726076] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1406.251511] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1406.393829] LustreError: 73351:0:(ldlm_lib.c:1113: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. [ 1406.400576] LustreError: 73351:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 12 previous similar messages [ 1406.439623] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3208 to 0x280000401:3233) [ 1407.759507] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1410.760238] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1412.241014] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1413.232937] Lustre: 76532:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1413.235732] Lustre: 76532:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 1418.516702] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1419.694892] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3145 to 0x2c0000401:3169) [ 1420.582166] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1423.858350] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1431.577326] Lustre: *** cfs_fail_loc=160d, val=0*** [ 1433.311334] Lustre: Failing over lustre-OST0000 [ 1433.339315] Lustre: server umount lustre-OST0000 complete [ 1436.295794] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1436.340901] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1436.344457] Lustre: Skipped 6 previous similar messages [ 1437.739745] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1437.745583] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1437.746734] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 192.168.201.133@tcp (at 0@lo) [ 1437.748287] Lustre: *** cfs_fail_loc=215, val=0*** [ 1437.752551] Lustre: Skipped 3 previous similar messages [ 1437.756819] Lustre: Skipped 1 previous similar message [ 1438.186760] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1439.429680] Lustre: 79395:0:(ofd_dev.c:560:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1439.436732] Lustre: 79395:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1440.340778] Lustre: Failing over lustre-OST0000 [ 1440.370843] Lustre: server umount lustre-OST0000 complete [ 1443.378229] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1444.978548] Lustre: *** cfs_fail_loc=215, val=0*** [ 1444.980381] Lustre: Skipped 1 previous similar message [ 1445.369272] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1448.928050] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1448.930990] Lustre: Skipped 6 previous similar messages [ 1453.460566] Lustre: server umount lustre-MDT0000 complete [ 1454.640720] LustreError: 78019:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754407100 with bad export cookie 10444330564657533633 [ 1454.643850] LustreError: 78019:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1454.769636] Lustre: server umount lustre-MDT0001 complete [ 1466.365875] Lustre: server umount lustre-OST0000 complete [ 1476.781951] Lustre: server umount lustre-OST0001 complete [ 1479.724122] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 11:18:43 (1754407123) [ 1484.274693] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1487.327933] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1488.593073] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1491.396623] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1492.805685] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1493.826486] Lustre: 83685:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1493.830254] Lustre: 83685:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 1496.189218] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1497.313809] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3298 to 0x280000401:3329) [ 1498.180617] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1501.117880] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1502.179888] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3145 to 0x2c0000401:3201) [ 1503.015374] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1506.107728] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1521.323828] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 11:19:25 (1754407165) [ 1525.644831] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 11:19:29 (1754407169) [ 1526.036980] Lustre: *** cfs_fail_loc=160f, val=0*** [ 1529.313953] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 11:19:33 (1754407173) [ 1530.329753] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1530.331470] Lustre: Skipped 7 previous similar messages [ 1568.223718] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1572.247467] Lustre: server umount lustre-MDT0000 complete [ 1573.553809] LustreError: 83688:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754407218 with bad export cookie 10444330564657542271 [ 1573.558424] LustreError: 83688:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1573.688685] Lustre: server umount lustre-MDT0001 complete [ 1585.219435] Lustre: server umount lustre-OST0000 complete [ 1595.812866] Lustre: server umount lustre-OST0001 complete [ 1600.651352] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1603.969042] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1604.116464] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1604.119531] Lustre: Skipped 10 previous similar messages [ 1605.375450] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1608.393860] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1609.852492] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1613.585232] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1616.176444] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1617.826973] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 1619.317908] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1620.849227] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 1621.395147] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1629.026761] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3253 to 0x2c0000401:3297) [ 1629.027449] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3490 to 0x280000401:3521) [ 1635.109389] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1636.438752] Lustre: 93174:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1636.442438] Lustre: 93174:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 2 previous similar messages [ 1643.920469] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 11:21:28 (1754407288) [ 1645.615542] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1645.616770] Lustre: Skipped 63 previous similar messages [ 1654.753409] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1654.756301] Lustre: Skipped 6 previous similar messages [ 1658.138274] Lustre: server umount lustre-MDT0000 complete [ 1659.558520] LustreError: 90203:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754407304 with bad export cookie 10444330564657570677 [ 1659.563673] LustreError: 90203:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1659.745382] Lustre: server umount lustre-MDT0001 complete [ 1671.560209] Lustre: server umount lustre-OST0000 complete [ 1683.270197] Lustre: server umount lustre-OST0001 complete [ 1688.819984] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1692.497623] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1693.865461] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1696.874885] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1698.369644] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1701.830083] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1702.947572] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3618 to 0x280000401:3649) [ 1703.881460] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1706.825112] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1707.939433] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 1707.940923] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 1707.941756] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3253 to 0x2c0000401:3329) [ 1708.927688] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1712.082629] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1720.548505] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 11:22:44 (1754407364) [ 1721.782178] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1721.783889] Lustre: Skipped 63 previous similar messages [ 1721.785290] Lustre: 97499:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 1721.788775] Lustre: 97499:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 1087 previous similar messages [ 1721.791172] Lustre: 97499:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1721.793640] Lustre: 97499:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 1087 previous similar messages [ 1721.795906] Lustre: 97499:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 1721.797693] Lustre: 97499:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 1087 previous similar messages [ 1721.799786] Lustre: 97499:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1721.801691] Lustre: 97499:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 1087 previous similar messages [ 1721.803492] Lustre: 97499:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1721.805331] Lustre: 97499:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 1087 previous similar messages [ 1721.807102] Lustre: 97499:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1721.808952] Lustre: 97499:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 1087 previous similar messages [ 1721.878058] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1725.693401] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 11:22:49 (1754407369) [ 1726.412580] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1726.435850] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1726.436882] Lustre: Skipped 2 previous similar messages [ 1730.129844] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 11:22:54 (1754407374) [ 1730.626553] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 1731.148232] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 11:22:55 (1754407375) [ 1734.084399] Lustre: *** cfs_fail_loc=1709, val=0*** [ 1734.160776] LustreError: 100169:0:(mdt_reint.c:2564:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240002340:0x6c:0x0]/f70 failed: rc = -5 [ 1737.521892] LustreError: 96037:0:(lod_object.c:930:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x3f:0x0]:1 for the striped directory [0x240002340:0xd1:0x0] is out of the known LMV EA range [0 - 0], failout [ 1738.230620] LustreError: 96036:0:(lod_object.c:930:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x3f:0x0]:1 for the striped directory [0x240002340:0xd1:0x0] is out of the known LMV EA range [0 - 0], failout [ 1738.236100] LustreError: 96036:0:(mdt_handler.c:1496:mdt_getattr_internal()) lustre-MDT0001: getattr error for [0x240002340:0xd1:0x0]: rc = -5 [ 1774.047942] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1777.110194] Lustre: server umount lustre-MDT0000 complete [ 1779.982793] LustreError: 100483:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754407425 with bad export cookie 10444330564657585405 [ 1779.988018] LustreError: 100483:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1780.122535] Lustre: server umount lustre-MDT0001 complete [ 1793.025196] Lustre: server umount lustre-OST0000 complete [ 1805.746063] Lustre: server umount lustre-OST0001 complete [ 1811.815157] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing unload_modules_local [ 1812.975396] Key type lgssc unregistered [ 1813.119564] LNet: 102770:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 1813.122790] LNetError: 102770:0:(acceptor.c:254:lnet_acceptor_remove_socket()) Interface ens2 not found [ 1813.132527] LNet: Removed LNI 192.168.201.133@tcp [ 1813.515117] Key type .llcrypt unregistered [ 1813.516407] Key type ._llcrypt unregistered [ 1822.157363] Key type ._llcrypt registered [ 1822.158672] Key type .llcrypt registered [ 1822.204189] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_hostid [ 1828.032381] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1828.543040] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 1828.579102] alg: No test for adler32 (adler32-zlib) [ 1829.479365] Lustre: Lustre: Build Version: 2.16.57_28_g7ecc534 [ 1829.576681] LNet: Added LNI 192.168.201.133@tcp [8/256/0/180] [ 1831.159240] Key type lgssc registered [ 1831.607654] Lustre: Echo OBD driver; http://www.lustre.org/ [ 1835.176948] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1838.052556] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1840.863592] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1843.946745] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1849.666556] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1854.538319] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1854.558379] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 1854.564826] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1855.658589] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1855.673190] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1855.710428] Lustre: lustre-MDT0000: new disk, initializing [ 1855.739209] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1855.748016] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1857.206575] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1862.652183] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1862.681298] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1862.705888] Lustre: 107130:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1862.718556] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1862.720716] Lustre: Skipped 1 previous similar message [ 1862.757220] Lustre: lustre-MDT0001: new disk, initializing [ 1862.779502] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1862.789279] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1862.792965] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1864.144399] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1866.562596] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1870.135252] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1870.156869] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1870.226046] Lustre: lustre-OST0000: new disk, initializing [ 1870.227757] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1870.242699] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1872.303605] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1875.439916] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1875.442890] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1875.461040] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1877.790867] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1877.820901] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1877.856756] Lustre: lustre-OST0001: new disk, initializing [ 1877.858420] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1877.874295] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 1879.847269] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1882.090372] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1882.095219] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1882.110255] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1885.335863] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1890.066765] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1897.066096] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 11:25:41 (1754407541) === [ 1899.283739] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 11:25:43 (1754407543) [ 1899.457612] Lustre: 109018:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 1899.461312] Lustre: 109018:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1899.463864] Lustre: 109018:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 1899.468351] Lustre: 109018:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 1899.471737] Lustre: 109018:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1899.474028] Lustre: 109018:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1900.242888] Lustre: *** cfs_fail_loc=1613, val=0*** [ 1903.550195] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 11:25:47 (1754407547) [ 1904.201788] Lustre: *** cfs_fail_loc=1614, val=0*** [ 1904.252392] Lustre: 109018:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 1904.255848] Lustre: 109018:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1904.259105] Lustre: 109018:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 1904.262059] Lustre: 109018:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 1904.265615] Lustre: 109018:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1904.268574] Lustre: 109018:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1905.701254] Lustre: 109018:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 1905.705313] Lustre: 109018:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1905.707681] Lustre: 109018:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 1905.710238] Lustre: 109018:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1905.713528] Lustre: 109018:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1905.716510] Lustre: 109018:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1907.999352] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 11:25:52 (1754407552) [ 1908.358849] Lustre: 109018:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 275, rollback = 2 [ 1908.362544] Lustre: 109018:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 1 previous similar message [ 1908.365641] Lustre: 109018:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1908.368289] Lustre: 109018:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1908.371125] Lustre: 109018:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/275/0 [ 1908.373691] Lustre: 109018:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1908.375781] Lustre: 109018:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1908.377776] Lustre: 109018:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1908.380538] Lustre: 109018:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1908.382699] Lustre: 109018:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1908.385225] Lustre: 109018:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1908.387095] Lustre: 109018:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1908.831971] Lustre: *** cfs_fail_loc=1615, val=0*** [ 1908.834031] Lustre: Skipped 1 previous similar message [ 1912.250705] LustreError: 112323:0:(lfsck_layout.c:2095:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x280000401:0x6d:0x0] and [0x280000401:0x6d:0x0]d: rc = 0 [ 1916.226021] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 1916.760062] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 11:26:01 (1754407561) [ 1917.509109] Lustre: *** cfs_fail_loc=1617, val=0*** [ 1917.537229] Lustre: *** cfs_fail_loc=1617, val=0*** [ 1918.299548] Lustre: *** cfs_fail_loc=1616, val=0*** [ 1918.301291] Lustre: Skipped 5 previous similar messages [ 1925.813251] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 11:26:09 (1754407569) [ 1926.121070] Lustre: 109018:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 1926.125407] Lustre: 109018:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 4 previous similar messages [ 1926.128232] Lustre: 109018:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1926.131348] Lustre: 109018:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1926.134352] Lustre: 109018:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 1926.136890] Lustre: 109018:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1926.139949] Lustre: 109018:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1926.143445] Lustre: 109018:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1926.148087] Lustre: 109018:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1926.151260] Lustre: 109018:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1926.154834] Lustre: 109018:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1926.157942] Lustre: 109018:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1926.712430] Lustre: *** cfs_fail_loc=1618, val=0*** [ 1926.714137] Lustre: Skipped 5 previous similar messages [ 1958.879569] 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 [ 1958.880094] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1958.884740] Lustre: Skipped 2 previous similar messages [ 1958.887853] Lustre: Skipped 1 previous similar message [ 1963.999670] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1964.002909] Lustre: Skipped 3 previous similar messages [ 1964.482522] LustreError: 113922:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 1964.522504] Lustre: server umount lustre-MDT0000 complete [ 1965.937755] LustreError: 107121:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754407611 with bad export cookie 11594071555691008146 [ 1965.939455] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1965.943175] LustreError: 107121:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1966.007500] LustreError: 114124:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 1966.009659] LustreError: 114124:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1966.081525] Lustre: server umount lustre-MDT0001 complete [ 1977.330173] LustreError: 114324:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 1977.332437] LustreError: 114324:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1977.352342] Lustre: server umount lustre-OST0000 complete [ 1988.975175] LustreError: 114526:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 1988.977914] LustreError: 114526:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1989.051930] Lustre: server umount lustre-OST0001 complete [ 1994.548232] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 1998.646381] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1998.836166] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2000.316537] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2003.625987] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2005.303932] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2006.377448] Lustre: 116787:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2008.849404] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2008.986851] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2008.993135] Lustre: Skipped 1 previous similar message [ 2011.123380] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2014.113772] LustreError: 117142:0:(ldlm_lib.c:1113: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. [ 2014.116594] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 2014.122089] LustreError: 117142:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 2 previous similar messages [ 2014.339566] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2016.108793] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 2016.431686] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2024.289804] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 2024.289838] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 2030.253471] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2031.401165] Lustre: 118638:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2040.715428] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 11:28:04 (1754407684) [ 2040.915435] Lustre: 117148:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 2040.918789] Lustre: 117148:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 3 previous similar messages [ 2040.921773] Lustre: 117148:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2040.924877] Lustre: 117148:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2040.927775] Lustre: 117148:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 2040.929877] Lustre: 117148:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2040.931824] Lustre: 117148:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 2040.934024] Lustre: 117148:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2040.936709] Lustre: 117148:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2040.939544] Lustre: 117148:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2040.942102] Lustre: 117148:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2040.944375] Lustre: 117148:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2041.398102] Lustre: *** cfs_fail_loc=1618, val=0*** [ 2041.399818] Lustre: Skipped 3 previous similar messages [ 2075.616774] 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 [ 2075.617252] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2075.621868] Lustre: Skipped 3 previous similar messages [ 2075.624789] Lustre: Skipped 1 previous similar message [ 2075.626859] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2079.033858] LustreError: 119413:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2079.036708] LustreError: 119413:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 2079.062645] Lustre: server umount lustre-MDT0000 complete [ 2080.277199] LustreError: 115670:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754407725 with bad export cookie 11594071555691023343 [ 2080.279032] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2080.282667] LustreError: 115670:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2080.404942] Lustre: server umount lustre-MDT0001 complete [ 2091.825088] LustreError: 119816:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 2091.828729] LustreError: 119816:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 2091.846425] Lustre: server umount lustre-OST0000 complete [ 2103.411353] Lustre: server umount lustre-OST0001 complete [ 2108.888888] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 2112.329766] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2112.466276] LustreError: 121182:0:(ldlm_lib.c:1113: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. [ 2112.487503] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2112.489853] Lustre: Skipped 1 previous similar message [ 2113.702194] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2116.550910] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2117.892593] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2118.811240] Lustre: 122277:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2120.932722] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2122.081077] LustreError: 122635:0:(ldlm_lib.c:1113: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. [ 2122.082198] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 2122.752323] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2125.581571] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2126.691433] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 2126.691826] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 2126.692319] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 2127.634543] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2130.685832] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2131.818405] Lustre: 124112:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2138.659965] Lustre: 121892:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 2138.664558] Lustre: 121892:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 3 previous similar messages [ 2138.668448] Lustre: 121892:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2138.671663] Lustre: 121892:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2138.676241] Lustre: 121892:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 2138.680679] Lustre: 121892:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2138.683634] LustreError: 124375:0:(lfsck_layout.c:4684:lfsck_layout_double_scan_one_trace_file()) cfs_fail_timeout id 1602 sleeping for 10000ms [ 2138.684452] Lustre: 121892:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 4/150/2 [ 2138.692919] Lustre: 121892:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2138.695691] Lustre: 121892:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 2138.700555] Lustre: 121892:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2138.704512] Lustre: 121892:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2138.706892] Lustre: 121892:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 2141.319055] LustreError: 124367:0:(lfsck_layout.c:3380:lfsck_layout_scan_orphan()) cfs_fail_timeout interrupted [ 2146.084732] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 11:29:50 (1754407790) [ 2146.892445] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2146.894203] Lustre: Skipped 3 previous similar messages [ 2150.368414] Lustre: *** cfs_fail_loc=161c, val=0*** [ 2156.448955] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 11:30:00 (1754407800) [ 2157.046432] Lustre: *** cfs_fail_loc=162e, val=0*** [ 2161.343825] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 11:30:05 (1754407805) [ 2162.904177] LustreError: 126941:0:(lfsck_layout.c:2095:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x2c0000401:0x45:0x0] and [0x2c0000401:0x45:0x0]d: rc = 0 [ 2166.776200] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 11:30:11 (1754407811) [ 2171.734824] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 11:30:15 (1754407815) [ 2172.699574] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2172.700818] Lustre: 122639:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 2172.703478] Lustre: 122639:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 17 previous similar messages [ 2172.705408] Lustre: 122639:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2172.710036] Lustre: 122639:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 2172.714251] Lustre: 122639:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 2172.718292] Lustre: 122639:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 2172.720848] Lustre: 122639:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 2172.723062] Lustre: 122639:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 2172.725137] Lustre: 122639:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2172.727070] Lustre: 122639:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 2172.729199] Lustre: 122639:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2172.731248] Lustre: 122639:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 2172.743240] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2172.745192] Lustre: Skipped 3 previous similar messages [ 2174.720316] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.201.33@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 2175.744110] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.201.33@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 2178.349996] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 11:30:22 (1754407822) [ 2179.148662] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2179.151183] Lustre: Skipped 11 previous similar messages [ 2209.652615] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 11:30:53 (1754407853) [ 2211.255113] Lustre: *** cfs_fail_loc=161a, val=1*** [ 2211.256827] Lustre: Skipped 11 previous similar messages [ 2213.904449] LustreError: 129168:0:(lfsck_layout.c:2095:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x2c0000401:0x4d:0x0] and [0x2c0000401:0x4d:0x0]d: rc = 0 [ 2219.719694] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 11:31:03 (1754407863) [ 2223.625879] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 11:31:07 (1754407867) [ 2224.219575] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2224.221899] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2224.223206] Lustre: Skipped 1 previous similar message [ 2227.731649] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 11:31:11 (1754407871) [ 2228.224699] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2228.226381] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2231.766617] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 11:31:15 (1754407875) [ 2232.299269] Lustre: *** cfs_fail_loc=1620, val=0*** [ 2236.622583] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 2237.168552] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 11:31:21 (1754407881) [ 2239.010549] Lustre: *** cfs_fail_loc=1621, val=142*** [ 2239.012414] Lustre: Skipped 1 previous similar message [ 2239.943275] LustreError: 131880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout id 1602 sleeping for 10000ms [ 2239.946463] LustreError: 131880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 1 previous similar message [ 2239.978159] Lustre: 125024:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 2239.980764] Lustre: 125024:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 21 previous similar messages [ 2239.983069] Lustre: 125024:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2239.984965] Lustre: 125024:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2239.986923] Lustre: 125024:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 2239.988941] Lustre: 125024:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2239.990970] Lustre: 125024:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 2239.993094] Lustre: 125024:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2239.995174] Lustre: 125024:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2239.997015] Lustre: 125024:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2239.999206] Lustre: 125024:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2240.001138] Lustre: 125024:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2240.368068] LustreError: 131880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout interrupted [ 2240.372452] LustreError: 131880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 1 previous similar message [ 2243.608424] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 11:31:27 (1754407887) [ 2244.326361] Lustre: Failing over lustre-MDT0000 [ 2244.576076] 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 [ 2244.576329] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2244.576358] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2244.580269] Lustre: Skipped 3 previous similar messages [ 2244.582057] Lustre: Skipped 2 previous similar messages [ 2244.587175] LustreError: 132367:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2244.589009] LustreError: 132367:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 2244.614218] Lustre: server umount lustre-MDT0000 complete [ 2245.900675] LustreError: 127496:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.33@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2247.976706] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2248.020195] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2248.100524] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2248.104488] Lustre: Skipped 3 previous similar messages [ 2248.127286] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2249.459556] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2253.055704] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2253.280936] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 2253.287756] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2253.293333] LustreError: 121177:0:(mdt_open.c:1315:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x91:0x0] doesn't exist!: rc = -14 [ 2253.303057] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:271 to 0x280000401:289) [ 2253.303091] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:138 to 0x2c0000401:161) [ 2256.444545] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 11:31:40 (1754407900) [ 2256.996442] Lustre: *** cfs_fail_loc=1622, val=0*** [ 2257.023559] Lustre: *** cfs_fail_loc=1622, val=0*** [ 2257.025163] Lustre: Skipped 1 previous similar message [ 2260.308722] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 11:31:44 (1754407904) [ 2260.772354] Lustre: *** cfs_fail_loc=1623, val=0*** [ 2264.219618] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 11:31:48 (1754407908) [ 2268.052718] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 11:31:52 (1754407912) [ 2268.540099] Lustre: *** cfs_fail_loc=1624, val=0*** [ 2268.541456] Lustre: Skipped 1 previous similar message [ 2271.968381] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 11:31:56 (1754407916) [ 2275.960355] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 11:32:00 (1754407920) [ 2279.945508] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 11:32:04 (1754407924) [ 2282.063680] Lustre: *** cfs_fail_loc=161c, val=0*** [ 2282.066071] Lustre: Skipped 2 previous similar messages [ 2287.429562] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 11:32:11 (1754407931) [ 2288.022725] Lustre: *** cfs_fail_loc=1626, val=0*** [ 2288.024888] Lustre: Skipped 5 previous similar messages [ 2291.713543] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 11:32:15 (1754407935) [ 2301.602825] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 11:32:25 (1754407945) [ 2302.346753] LustreError: 121177:0:(osd_handler.c:272:osd_idc_find_or_init()) can't lookup: rc = -2 [ 2304.300977] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 11:32:28 (1754407948) [ 2306.452376] Lustre: Failing over lustre-MDT0000 [ 2306.561143] LustreError: 138787:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2306.564046] LustreError: 138787:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2306.593074] Lustre: server umount lustre-MDT0000 complete [ 2309.599450] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2309.600836] 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 [ 2309.602378] LustreError: 121182:0:(ldlm_lib.c:1113: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. [ 2309.607742] Lustre: Skipped 4 previous similar messages [ 2309.614290] LustreError: 121182:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 4 previous similar messages [ 2309.912164] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2309.944414] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2310.025969] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2311.396653] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2315.232675] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2315.233596] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 2315.238791] Lustre: Skipped 3 previous similar messages [ 2315.239584] LustreError: 139367:0:(fld_handler.c:205:fld_local_lookup()) srv-lustre-MDT0000: FLD cache range [0x0000000280000400-0x00000002c0000400]:0:ost does not match requested flag 0: rc = -5 [ 2315.246847] LustreError: 139367:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 2315.253658] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2315.271604] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:321) [ 2315.271614] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:193) [ 2319.186946] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 11:32:43 (1754407963) [ 2322.980153] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 11:32:47 (1754407967) [ 2326.952703] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 11:32:51 (1754407971) [ 2327.395220] Lustre: *** cfs_fail_loc=1629, val=0*** [ 2327.397019] Lustre: Skipped 3 previous similar messages [ 2357.746653] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 11:33:21 (1754408001) [ 2359.333606] Lustre: Failing over lustre-MDT0000 [ 2361.311766] 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 [ 2361.312437] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2361.312448] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2361.316847] Lustre: Skipped 1 previous similar message [ 2361.318547] Lustre: Skipped 2 previous similar messages [ 2364.981450] Lustre: server umount lustre-MDT0000 complete [ 2366.431467] LustreError: 122643:0:(ldlm_lib.c:1113: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. [ 2366.435639] LustreError: 122643:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 3 previous similar messages [ 2367.779444] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2367.808673] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2367.870645] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2367.872873] Lustre: Skipped 1 previous similar message [ 2367.882883] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2369.204221] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2369.911635] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2369.914105] Lustre: lustre-MDT0000: Denying connection for new client 910c8c34-3865-4103-9eb6-2da49a2762dd (at 192.168.201.33@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 2373.089429] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 2373.091040] Lustre: Skipped 3 previous similar messages [ 2373.091208] LustreError: 142034:0:(fld_handler.c:205:fld_local_lookup()) srv-lustre-MDT0000: FLD cache range [0x0000000280000400-0x00000002c0000400]:0:ost does not match requested flag 0: rc = -5 [ 2373.096299] LustreError: 142034:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 2373.104399] Lustre: lustre-MDT0000: Recovery over after 0:04, of 1 clients 1 recovered and 0 were evicted. [ 2373.121322] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:353) [ 2373.121358] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:225) [ 2375.485403] Lustre: 123600:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 2375.487852] Lustre: 123600:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 114 previous similar messages [ 2375.489640] Lustre: 123600:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2375.491380] Lustre: 123600:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2375.493507] Lustre: 123600:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 2375.495376] Lustre: 123600:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2375.498342] Lustre: 123600:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 2375.502078] Lustre: 123600:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2375.505582] Lustre: 123600:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2375.508921] Lustre: 123600:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2375.512412] Lustre: 123600:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2375.515763] Lustre: 123600:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2377.613847] Lustre: Failing over lustre-MDT0000 [ 2377.840271] LustreError: 142723:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2377.842841] LustreError: 142723:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 2377.870407] Lustre: server umount lustre-MDT0000 complete [ 2378.208648] 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 [ 2378.208762] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2378.211456] Lustre: Skipped 3 previous similar messages [ 2380.545250] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2380.575736] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2380.656809] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2381.921111] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2385.664190] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2385.890068] LustreError: 143204:0:(fld_handler.c:205:fld_local_lookup()) srv-lustre-MDT0000: FLD cache range [0x0000000280000400-0x00000002c0000400]:0:ost does not match requested flag 0: rc = -5 [ 2385.893392] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 2385.896402] LustreError: 143204:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 2385.897826] Lustre: Skipped 3 previous similar messages [ 2385.909250] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2385.924513] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:355 to 0x280000401:385) [ 2385.924513] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:257) [ 2387.907221] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 11:33:52 (1754408032) [ 2391.557221] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 11:33:55 (1754408035) [ 2395.369727] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 11:33:59 (1754408039) [ 2431.957693] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 11:34:35 (1754408075) [ 2443.166958] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 11:34:46 (1754408086) [ 2450.252684] LustreError: 145638:0:(lfsck_layout.c:4469:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2452.321906] Lustre: Failing over lustre-OST0000 [ 2452.412673] Lustre: server umount lustre-OST0000 complete [ 2452.449115] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2452.451170] LustreError: 122635:0:(ldlm_lib.c:1113: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. [ 2452.466409] Lustre: Skipped 3 previous similar messages [ 2452.480969] LustreError: 122635:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 5 previous similar messages [ 2453.319114] LustreError: 145638:0:(lfsck_layout.c:4469:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 2453.327126] LustreError: 145638:0:(lfsck_layout.c:4469:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2454.490119] LustreError: 145638:0:(lfsck_layout.c:4469:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 2462.655754] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2462.767780] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2464.501846] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2464.518963] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2464.519116] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 192.168.201.133@tcp (at 0@lo) [ 2464.526640] Lustre: Skipped 3 previous similar messages [ 2465.467840] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2469.998796] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 11:35:13 (1754408113) [ 2476.583849] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 2484.787278] Lustre: 148406:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2495.458420] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2508.059823] LustreError: 149657:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2508.066738] LustreError: 149657:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 2509.426206] Lustre: Failing over lustre-MDT0001 [ 2511.079084] LustreError: 149654:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 2511.085279] LustreError: lustre-MDT0001-osp-MDT0000: operation out_update to node 0@lo failed: rc = -107 [ 2511.088565] 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 [ 2511.098861] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2511.167913] LustreError: 149806:0:(obd_class.h:479:obd_check_dev()) Device 18 not setup [ 2511.171027] LustreError: 149806:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 2511.228632] Lustre: server umount lustre-MDT0001 complete [ 2512.863121] LustreError: 149654:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 2513.888705] LustreError: 141045:0:(ldlm_lib.c:1113: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. [ 2513.895671] LustreError: 141045:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 7 previous similar messages [ 2520.830474] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2521.053219] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2521.056527] Lustre: Skipped 2 previous similar messages [ 2521.083192] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2523.075266] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2526.177235] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2526.178378] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to (at 0@lo) [ 2526.188532] Lustre: Skipped 1 previous similar message [ 2526.199851] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2526.246269] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:97) [ 2526.247182] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:97) [ 2527.523858] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 11:36:11 (1754408171) [ 2534.118089] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 2542.364883] Lustre: 152325:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2542.369430] Lustre: 152325:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 2551.526699] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2566.311994] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 11:36:50 (1754408210) [ 2566.888368] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 2567.577978] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 11:36:51 (1754408211) [ 2569.910478] Lustre: *** cfs_fail_loc=1631, val=0*** [ 2577.379801] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2577.381411] 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 [ 2577.381918] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2577.391621] Lustre: Skipped 5 previous similar messages [ 2582.452412] Lustre: server umount lustre-MDT0000 complete [ 2582.498069] LustreError: 121178:0:(ldlm_lib.c:1113: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. [ 2582.505698] LustreError: 121178:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 6 previous similar messages [ 2584.124161] LustreError: 121162:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754408229 with bad export cookie 11594071555691100210 [ 2584.126303] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2584.130145] LustreError: 121162:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2584.290501] Lustre: server umount lustre-MDT0001 complete [ 2595.850705] Lustre: server umount lustre-OST0000 complete [ 2607.694474] Lustre: server umount lustre-OST0001 complete [ 2614.170637] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 2618.233235] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2620.260882] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2624.427824] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2626.625361] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2628.293575] Lustre: 157277:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2628.298266] Lustre: 157277:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 2631.958607] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2634.212647] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:129) [ 2635.159702] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2638.927266] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2640.191776] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:129) [ 2641.869769] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2643.303463] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:414 to 0x2c0000401:449) [ 2643.304791] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:542 to 0x280000401:577) [ 2651.426546] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2662.342467] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 11:38:26 (1754408306) [ 2663.028485] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 2663.840163] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 11:38:27 (1754408307) [ 2664.528527] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 2665.271967] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 11:38:29 (1754408309) [ 2665.964907] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 2666.742118] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 11:38:30 (1754408310) [ 2671.086283] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 11:38:35 (1754408315) [ 2671.210292] Lustre: 158872:0:(osd_internal.h:1335:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 445, rollback = 2 [ 2671.217183] Lustre: 158872:0:(osd_internal.h:1335:osd_trans_exec_op()) Skipped 323 previous similar messages [ 2671.220821] Lustre: 158872:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 4/16/0, destroy: 0/0/0 [ 2671.225173] Lustre: 158872:0:(osd_handler.c:1966:osd_trans_dump_creds()) Skipped 324 previous similar messages [ 2671.232529] Lustre: 158872:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 4/4/0, xattr_set: 9/445/0 [ 2671.236643] Lustre: 158872:0:(osd_handler.c:1973:osd_trans_dump_creds()) Skipped 324 previous similar messages [ 2671.240406] Lustre: 158872:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 7/88/0, punch: 0/0/0, quota 1/3/0 [ 2671.244488] Lustre: 158872:0:(osd_handler.c:1983:osd_trans_dump_creds()) Skipped 324 previous similar messages [ 2671.248149] Lustre: 158872:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 13/232/2, delete: 0/0/0 [ 2671.253894] Lustre: 158872:0:(osd_handler.c:1990:osd_trans_dump_creds()) Skipped 324 previous similar messages [ 2671.257788] Lustre: 158872:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 5/5/0, ref_del: 0/0/0 [ 2671.261162] Lustre: 158872:0:(osd_handler.c:1997:osd_trans_dump_creds()) Skipped 324 previous similar messages [ 2677.424823] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 11:38:41 (1754408321) [ 2683.700349] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 11:38:47 (1754408327) [ 2690.583744] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 11:38:54 (1754408334) [ 2699.234101] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK can repair inconsistent MDT-object/OST-object encryption flags ========================================================== 11:39:03 (1754408343) [ 2731.339377] Lustre: *** cfs_fail_loc=1632, val=0*** [ 2737.974281] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 11:39:41 (1754408381) [ 2739.597766] Lustre: Failing over lustre-MDT0001 [ 2739.724475] Lustre: server umount lustre-MDT0001 complete [ 2740.705812] 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 [ 2740.717806] LustreError: 156891:0:(ldlm_lib.c:1113: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. [ 2740.725323] LustreError: 156891:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 5 previous similar messages [ 2743.528889] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2743.703032] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2743.707578] Lustre: lustre-MDT0001: Aborting client recovery [ 2743.712687] LustreError: 162892:0:(ldlm_lib.c:2916:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 2743.716981] Lustre: 162920:0:(ldlm_lib.c:2319:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2743.721934] Lustre: 162920:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client f9c731e3-c16b-4be4-8bd4-866adfc24801@ [ 2743.728316] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 2743.738341] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 2743.746522] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 2743.771765] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 2743.775357] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:161) [ 2745.687301] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2748.897889] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 2748.909985] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to (at 0@lo) [ 2748.912543] Lustre: Skipped 2 previous similar messages [ 2749.554719] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 2749.717162] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 2752.925168] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 11:39:56 (1754408396) [ 2758.217244] LustreError: 163891:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 3000ms [ 2758.228987] LustreError: 163891:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) Skipped 1 previous similar message [ 2760.221430] Lustre: Failing over lustre-MDT0000 [ 2761.247228] LustreError: 163891:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 awake [ 2761.250769] LustreError: 163891:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) Skipped 1 previous similar message [ 2761.387678] Lustre: server umount lustre-MDT0000 complete [ 2764.256394] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2765.990156] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2766.063445] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2767.106636] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2768.114399] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2771.430043] LustreError: 164576:0:(fld_handler.c:205:fld_local_lookup()) srv-lustre-MDT0000: FLD cache range [0x0000000280000400-0x00000002c0000400]:0:ost does not match requested flag 0: rc = -5 [ 2771.438128] LustreError: 164576:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 2771.447595] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 2771.475096] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:622 to 0x280000401:641) [ 2771.475834] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 2772.536599] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 11:40:16 (1754408416) [ 2785.578155] Lustre: Failing over lustre-OST0000 [ 2785.608281] LustreError: 165734:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 2785.612501] LustreError: 165734:0:(obd_class.h:479:obd_check_dev()) Skipped 49 previous similar messages [ 2785.660185] Lustre: server umount lustre-OST0000 complete [ 2788.984335] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2794.762573] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2794.876710] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2794.881204] Lustre: Skipped 6 previous similar messages [ 2794.888257] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2794.896031] Lustre: Skipped 3 previous similar messages [ 2796.724466] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 192.168.201.133@tcp (at 0@lo) [ 2796.728922] Lustre: Skipped 5 previous similar messages [ 2797.727495] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2817.510754] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2817.513826] Lustre: Skipped 3 previous similar messages [ 2823.087197] Lustre: server umount lustre-MDT0000 complete [ 2827.315591] LustreError: 156902:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754408472 with bad export cookie 11594071555691183657 [ 2827.322126] LustreError: 156902:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2827.699337] Lustre: server umount lustre-MDT0001 complete [ 2842.392722] Lustre: server umount lustre-OST0000 complete [ 2856.445026] Lustre: server umount lustre-OST0001 complete [ 2862.993300] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing unload_modules_local [ 2864.383778] Key type lgssc unregistered [ 2864.552529] LNet: 170509:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2864.557386] LNetError: 170509:0:(acceptor.c:254:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2864.571484] LNet: Removed LNI 192.168.201.133@tcp [ 2864.979150] Key type .llcrypt unregistered [ 2864.980639] Key type ._llcrypt unregistered [ 2874.934593] Key type ._llcrypt registered [ 2874.936369] Key type .llcrypt registered [ 2874.981672] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_hostid [ 2881.911381] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 2882.410753] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 2882.420208] alg: No test for adler32 (adler32-zlib) [ 2883.327469] Lustre: Lustre: Build Version: 2.16.57_28_g7ecc534 [ 2883.442462] LNet: Added LNI 192.168.201.133@tcp [8/256/0/180] [ 2885.055941] Key type lgssc registered [ 2885.550231] Lustre: Echo OBD driver; http://www.lustre.org/ [ 2891.026387] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2895.449855] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2898.425240] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2901.467727] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2907.237371] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing load_modules_local [ 2913.439376] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2913.486537] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 2913.516723] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2914.642874] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2914.665760] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2914.715244] Lustre: lustre-MDT0000: new disk, initializing [ 2914.769919] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2914.789765] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2916.608761] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2922.126565] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2922.160841] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2922.192052] Lustre: 174887:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2922.205574] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2922.207238] Lustre: Skipped 1 previous similar message [ 2922.247342] Lustre: lustre-MDT0001: new disk, initializing [ 2922.271145] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2922.281617] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2922.284529] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2923.612134] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2926.026706] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2929.561290] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2929.590629] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2929.680734] Lustre: lustre-OST0000: new disk, initializing [ 2929.682610] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2929.702837] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2931.915194] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2936.315174] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2936.319665] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2936.378544] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2938.151444] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2938.194953] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2938.248995] Lustre: lustre-OST0001: new disk, initializing [ 2938.252751] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2938.281942] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2940.627255] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2942.963647] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2942.967439] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2942.986427] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2947.726916] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2950.656332] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2958.365568] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 11:43:22 (1754408602) === [ 2959.138887] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 2761 sec ========= 11:43:23 (1754408603) [ 2959.930553] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 11:43:23 (1754408603) === [ 2961.477594] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 11:43:25 (1754408605) === [ 2963.425221] 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 [ 2963.428969] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2963.431954] Lustre: Skipped 3 previous similar messages [ 2963.435316] Lustre: Skipped 2 previous similar messages [ 2963.440126] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2968.544091] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2968.546638] Lustre: Skipped 4 previous similar messages [ 2969.093473] LustreError: 179040:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 2969.144271] Lustre: server umount lustre-MDT0000 complete [ 2972.886913] LustreError: 174880:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1754408618 with bad export cookie 13513841900553563010 [ 2972.890713] LustreError: MGC192.168.201.133@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2972.892642] LustreError: 174880:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2972.970668] LustreError: 179490:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 2972.972858] LustreError: 179490:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2973.077229] Lustre: server umount lustre-MDT0001 complete [ 2987.249093] LustreError: 179941:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 2987.255543] LustreError: 179941:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2987.293174] Lustre: server umount lustre-OST0000 complete [ 2990.304068] Lustre: 172065:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1754408619/real 1754408619] req@ffff9cdb010adf80 x1839630676723200/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1754408635 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2990.318596] 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 [ 2991.660671] LustreError: 180392:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 2991.663490] LustreError: 180392:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2991.747684] Lustre: server umount lustre-OST0001 complete [ 2998.894977] Lustre: DEBUG MARKER: oleg133-server.virtnet: executing unload_modules_local [ 3000.208671] Key type lgssc unregistered [ 3000.377513] LNet: 181216:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3000.381264] LNetError: 181216:0:(acceptor.c:254:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3000.398083] LNet: Removed LNI 192.168.201.133@tcp [ 3000.756166] Key type .llcrypt unregistered [ 3000.757740] Key type ._llcrypt unregistered