[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-1.fc38 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 425314718 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 0x000f5b30-0x000f5b3f] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5950 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1BB7 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1A53 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001A13 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1AC7 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1B57 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1B8F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1a53-0xbffe1ac6] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1a52] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1ac7-0xbffe1b56] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1b57-0xbffe1b8e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1b8f-0xbffe1bb6] [ 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.001010] APIC: Switch to symmetric I/O mode setup [ 0.002245] x2apic enabled [ 0.003007] Switched APIC routing to physical x2apic. [ 0.004010] kvm-guest: setup PV IPIs [ 0.006650] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008003] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009006] pid_max: default: 32768 minimum: 301 [ 0.010135] LSM: Security Framework initializing [ 0.011036] Yama: becoming mindful. [ 0.012022] SELinux: Initializing. [ 0.013040] *** VALIDATE selinux *** [ 0.021033] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.025558] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026088] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027071] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028062] *** VALIDATE tmpfs *** [ 0.029436] *** VALIDATE proc *** [ 0.030163] *** VALIDATE cgroup *** [ 0.031005] *** VALIDATE cgroup2 *** [ 0.033118] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034101] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035003] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.036017] Spectre V2 : User space: Vulnerable [ 0.037005] Speculative Store Bypass: Vulnerable [ 0.040379] debug: unmapping init [mem 0xffffffff9cc59000-0xffffffff9cc60fff] [ 0.042140] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.043481] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.044018] ... version: 2 [ 0.045009] ... bit width: 48 [ 0.046008] ... generic registers: 4 [ 0.047008] ... value mask: 0000ffffffffffff [ 0.048007] ... max period: 00007fffffffffff [ 0.049009] ... fixed-purpose events: 3 [ 0.050007] ... event mask: 000000070000000f [ 0.051281] rcu: Hierarchical SRCU implementation. [ 0.053614] smp: Bringing up secondary CPUs ... [ 0.054390] x86: Booting SMP configuration: [ 0.055010] .... node #0, CPUs: #1 #2 #3 [ 0.057394] smp: Brought up 1 node, 4 CPUs [ 0.058786] smpboot: Max logical packages: 1 [ 0.059007] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.153026] node 0 deferred pages initialised in 93ms [ 0.156017] devtmpfs: initialized [ 0.157189] x86/mm: Memory block size: 128MB [ 0.159244] gcov: version magic: 0x41383552 [ 0.160600] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.164107] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.166345] pinctrl core: initialized pinctrl subsystem [ 0.168139] [ 0.168666] ************************************************************* [ 0.171009] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.173007] ** ** [ 0.175008] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.178009] ** ** [ 0.180006] ** This means that this kernel is built to expose internal ** [ 0.183010] ** IOMMU data structures, which may compromise security on ** [ 0.185007] ** your system. ** [ 0.187009] ** ** [ 0.189009] ** If you see this message and you are not debugging the ** [ 0.192008] ** kernel, report this immediately to your vendor! ** [ 0.195008] ** ** [ 0.198008] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.200007] ************************************************************* [ 0.203641] NET: Registered protocol family 16 [ 0.205442] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.208045] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.211043] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.215039] cpuidle: using governor menu [ 0.215800] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.218607] PCI: Using configuration type 1 for base access [ 0.221137] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.230065] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.232093] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.235090] cryptd: max_cpu_qlen set to 1000 [ 0.239033] ACPI: Added _OSI(Module Device) [ 0.239877] ACPI: Added _OSI(Processor Device) [ 0.241015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.243010] ACPI: Added _OSI(Processor Aggregator Device) [ 0.246695] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.254173] ACPI: Interpreter enabled [ 0.255049] ACPI: PM: (supports S0 S3 S4 S5) [ 0.257012] ACPI: Using IOAPIC for interrupt routing [ 0.259152] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.262417] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.273862] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.276022] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.278011] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.282075] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.287438] acpiphp: Slot [2] registered [ 0.289075] acpiphp: Slot [3] registered [ 0.290067] acpiphp: Slot [4] registered [ 0.291070] acpiphp: Slot [5] registered [ 0.293108] acpiphp: Slot [6] registered [ 0.294071] acpiphp: Slot [7] registered [ 0.296076] acpiphp: Slot [8] registered [ 0.297075] acpiphp: Slot [9] registered [ 0.299080] acpiphp: Slot [10] registered [ 0.300078] acpiphp: Slot [11] registered [ 0.302073] acpiphp: Slot [12] registered [ 0.303104] acpiphp: Slot [13] registered [ 0.305070] acpiphp: Slot [14] registered [ 0.306072] acpiphp: Slot [15] registered [ 0.308068] acpiphp: Slot [16] registered [ 0.309071] acpiphp: Slot [17] registered [ 0.311068] acpiphp: Slot [18] registered [ 0.312088] acpiphp: Slot [19] registered [ 0.314077] acpiphp: Slot [20] registered [ 0.315078] acpiphp: Slot [21] registered [ 0.316074] acpiphp: Slot [22] registered [ 0.318067] acpiphp: Slot [23] registered [ 0.319089] acpiphp: Slot [24] registered [ 0.321066] acpiphp: Slot [25] registered [ 0.322075] acpiphp: Slot [26] registered [ 0.324075] acpiphp: Slot [27] registered [ 0.325072] acpiphp: Slot [28] registered [ 0.327074] acpiphp: Slot [29] registered [ 0.328070] acpiphp: Slot [30] registered [ 0.330097] acpiphp: Slot [31] registered [ 0.331137] PCI host bridge to bus 0000:00 [ 0.333014] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.335015] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.338012] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.340011] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.343013] pci_bus 0000:00: root bus resource [mem 0x180000000-0x1ffffffff window] [ 0.346018] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.348178] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.352706] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.355553] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.362533] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.366056] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.367012] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.368015] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.370026] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.373559] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.375718] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.378050] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.381715] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.385814] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.396959] pci 0000:00:02.0: reg 0x20: [mem 0xfebe4000-0xfebe7fff 64bit pref] [ 0.400009] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.405296] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.412025] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.419024] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.431027] pci 0000:00:05.0: reg 0x20: [mem 0xfebe8000-0xfebebfff 64bit pref] [ 0.441334] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.447013] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.451017] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.466031] pci 0000:00:06.0: reg 0x20: [mem 0xfebec000-0xfebeffff 64bit pref] [ 0.477597] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.483015] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.490032] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.508054] pci 0000:00:07.0: reg 0x20: [mem 0xfebf0000-0xfebf3fff 64bit pref] [ 0.515024] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.520018] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.526015] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.538019] pci 0000:00:08.0: reg 0x20: [mem 0xfebf4000-0xfebf7fff 64bit pref] [ 0.548080] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.554015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.564021] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.577013] pci 0000:00:09.0: reg 0x20: [mem 0xfebf8000-0xfebfbfff 64bit pref] [ 0.586295] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.590016] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.597023] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.614044] pci 0000:00:0a.0: reg 0x20: [mem 0xfebfc000-0xfebfffff 64bit pref] [ 0.625419] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.630475] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.635582] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.638670] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.643429] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.650169] iommu: Default domain type: Passthrough [ 0.651450] SCSI subsystem initialized [ 0.652101] ACPI: bus type USB registered [ 0.653087] usbcore: registered new interface driver usbfs [ 0.654054] usbcore: registered new interface driver hub [ 0.656083] usbcore: registered new device driver usb [ 0.658119] pps_core: LinuxPPS API ver. 1 registered [ 0.658950] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.660035] PTP clock support registered [ 0.662093] EDAC MC: Ver: 3.0.0 [ 0.664191] PCI: Using ACPI for IRQ routing [ 0.666988] NetLabel: Initializing [ 0.668010] NetLabel: domain hash size = 128 [ 0.669014] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.671070] NetLabel: unlabeled traffic allowed by default [ 0.673119] vgaarb: loaded [ 0.674301] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.676007] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.680419] clocksource: Switched to clocksource kvm-clock [ 0.789882] VFS: Disk quotas dquot_6.6.0 [ 0.791030] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.792838] *** VALIDATE ramfs *** [ 0.793567] *** VALIDATE hugetlbfs *** [ 0.794874] pnp: PnP ACPI init [ 0.797534] pnp: PnP ACPI: found 6 devices [ 0.813492] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.816303] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.818136] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.820259] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.822506] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.824557] pci_bus 0000:00: resource 8 [mem 0x180000000-0x1ffffffff window] [ 0.827075] NET: Registered protocol family 2 [ 0.829200] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.833404] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.835973] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.840618] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.842763] TCP: Hash tables configured (established 65536 bind 65536) [ 0.845403] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.847573] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.850285] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.852501] NET: Registered protocol family 1 [ 0.854793] RPC: Registered named UNIX socket transport module. [ 0.856603] RPC: Registered udp transport module. [ 0.857608] RPC: Registered tcp transport module. [ 0.858865] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.860697] NET: Registered protocol family 44 [ 0.862083] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.863289] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.864826] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.866763] PCI: CLS 0 bytes, default 64 [ 0.869095] Unpacking initramfs... [ 2.298381] debug: unmapping init [mem 0xffffa076bcc54000-0xffffa076bffbffff] [ 2.301879] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.303441] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.305423] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.819483] Initialise system trusted keyrings [ 2.820913] Key type blacklist registered [ 2.824947] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.833585] zbud: loaded [ 2.836710] *** VALIDATE nfs *** [ 2.837814] *** VALIDATE nfs4 *** [ 2.838910] pstore: using deflate compression [ 2.842204] Platform Keyring initialized [ 2.963922] NET: Registered protocol family 38 [ 2.966825] Key type asymmetric registered [ 2.968791] Asymmetric key parser 'x509' registered [ 2.971347] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.974757] io scheduler mq-deadline registered [ 2.976258] io scheduler kyber registered [ 2.977630] io scheduler bfq registered [ 2.979558] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.982100] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.984561] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.987156] ACPI: Power Button [PWRF] [ 3.096474] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.205632] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.391827] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.493765] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.696652] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.724193] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.759548] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.767654] Non-volatile memory driver v1.3 [ 3.768875] Linux agpgart interface v0.103 [ 3.798173] virtio_blk virtio1: [vda] 133040 512-byte logical blocks (68.1 MB/65.0 MiB) [ 3.801926] vda: detected capacity change from 0 to 68116480 [ 3.817883] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.819922] vdb: detected capacity change from 0 to 1073741824 [ 3.836559] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.839315] vdc: detected capacity change from 0 to 2621440000 [ 3.856112] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.858691] vdd: detected capacity change from 0 to 2621440000 [ 3.872993] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.877557] vde: detected capacity change from 0 to 4294967296 [ 3.892873] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.895941] vdf: detected capacity change from 0 to 4294967296 [ 3.906121] libphy: Fixed MDIO Bus: probed [ 3.914036] usbcore: registered new interface driver usbserial_generic [ 3.918571] usbserial: USB Serial support registered for generic [ 3.920994] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.925580] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.928801] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.931168] mousedev: PS/2 mouse device common for all mice [ 3.933428] rtc_cmos 00:05: RTC can wake from S4 [ 3.936360] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.940618] rtc_cmos 00:05: registered as rtc0 [ 3.942480] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.945301] intel_pstate: CPU model not supported [ 3.947690] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.953787] hid: raw HID events driver (C) Jiri Kosina [ 3.956230] usbcore: registered new interface driver usbhid [ 3.958929] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.959542] usbhid: USB HID core driver [ 3.964220] drop_monitor: Initializing network drop monitor service [ 3.966800] Initializing XFRM netlink socket [ 3.969154] NET: Registered protocol family 10 [ 3.972458] Segment Routing with IPv6 [ 3.974131] NET: Registered protocol family 17 [ 3.976338] mpls_gso: MPLS GSO support [ 3.980054] RAS: Correctable Errors collector initialized. [ 3.982145] AVX version of gcm_enc/dec engaged. [ 3.983608] AES CTR mode by8 optimization enabled [ 4.091569] sched_clock: Marking stable (4091551073, 0)->(4836124245, -744573172) [ 4.095614] registered taskstats version 1 [ 4.097414] Loading compiled-in X.509 certificates [ 4.099510] zswap: loaded using pool lzo/zbud [ 4.140864] Key type big_key registered [ 4.162381] Key type encrypted registered [ 4.164399] ima: No TPM chip found, activating TPM-bypass! [ 4.169535] ima: Allocated hash algorithm: sha1 [ 4.171276] ima: No architecture policies found [ 4.173177] evm: Initialising EVM extended attributes: [ 4.175131] evm: security.selinux [ 4.176298] evm: security.ima [ 4.177172] evm: security.capability [ 4.178598] evm: HMAC attrs: 0x1 [ 4.183489] rtc_cmos 00:05: setting system clock to 2025-08-31 21:30:10 UTC (1756675810) [ 4.190661] debug: unmapping init [mem 0xffffffff9dc03000-0xffffffff9ddfffff] [ 4.193536] debug: unmapping init [mem 0xffffffff9c982000-0xffffffff9cc58fff] [ 4.203495] Write protecting the kernel read-only data: 28672k [ 4.207122] debug: unmapping init [mem 0xffffffff9b003000-0xffffffff9b1fffff] [ 4.209787] debug: unmapping init [mem 0xffffffff9b914000-0xffffffff9b9fffff] [ 4.262040] 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.268795] systemd[1]: Detected virtualization kvm. [ 4.270189] systemd[1]: Detected architecture x86-64. [ 4.271415] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.305807] systemd[1]: No hostname configured. [ 4.307933] systemd[1]: Set hostname to . [ 4.310083] random: systemd: uninitialized urandom read (16 bytes read) [ 4.313647] systemd[1]: Initializing machine ID from random generator. [ 4.534495] random: systemd: uninitialized urandom read (16 bytes read) [ 4.537419] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 4.552413] random: systemd: uninitialized urandom read (16 bytes read) [ 4.555303] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 4.559783] systemd[1]: Reached target Local Encrypted Volumes. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Timers. [ OK ] Reached target Local File Systems. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... [ OK ] Reached target Swap. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Kernel Socket. [ OK ] Started Memstrack Anylazing Service. Starting Apply Kernel Variables... Starting Setup Virtual Console... [ OK ] Reached target Initrd Root Device. Starting Journal Service... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ 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.435281] device-mapper: uevent: version 1.0.3 [ 5.437458] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 6.717544] virtio_net virtio0 ens2: renamed from eth0 [ 6.796719] random: fast init done [ 7.092466] scsi host0: ata_piix [ 7.099362] scsi host1: ata_piix [ 7.100634] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 7.102636] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 11.700900] random: crng init done [ 11.702980] random: 7 urandom warning(s) missed due to ratelimiting [ 14.042896] dracut-initqueue[587]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 15.896574] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Timers. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. Stopping udev Kernel Device Manager... [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 17.816242] printk: systemd: 26 output lines suppressed due to ratelimiting [ 18.265110] SELinux: Disabled at runtime. [ 18.350919] 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) [ 18.362186] systemd[1]: Detected virtualization kvm. [ 18.365613] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 19.226884] systemd[1]: initrd-switch-root.service: Succeeded. [ 19.230606] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 19.236479] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 19.240113] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 19.243411] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 19.250334] systemd[1]: Starting Journal Service... Starting Journal Service... [ 19.263547] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Listening on initctl Compatibility Named Pipe. Activating swap /dev/disk/by-label/SWAP... Mounting Kernel Debug File System... Mounting POSIX Message Queue File System... [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Created slice system-getty.slice. [ 19.443119] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Mounting Huge Pages File System... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on Process Core Dump Socket. Starting Apply Kernel Variables... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. [ 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 udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 20.340288] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 21.066639] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 21.151327] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 21.958137] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 22.046593] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (6s / no limit)[ 26.449165] Key type dns_resolver registered [** ] A start job is running for Configur…-only root support (7s / no limit)[ 27.095100] NFS: Registering the id_resolver key type [ 27.097578] Key type id_resolver registered [ 27.099419] Key type id_legacy registered [*** ] A start job is running for Configur…-only root support (7s / no limit) [ *** ] A start job is running for Configur…-only root support (8s / no limit) [ 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 update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Daily Cleanup of Temporary Directories. Starting Login Service... [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. Starting Restore /run/initramfs on shutdown... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started Login Service. Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ 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 Crash recovery kernel arming... Starting Notify NFS peers of a restart... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg241-server login: [ 51.991299] libcfs: loading out-of-tree module taints kernel. [ 52.001084] Key type ._llcrypt registered [ 52.002618] Key type .llcrypt registered [ 52.046462] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 59.098714] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 59.786498] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 59.793366] alg: No test for adler32 (adler32-zlib) [ 60.758210] Lustre: Lustre: Build Version: 2.16.58_1_g28cf6eb [ 61.037475] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 62.656115] Key type lgssc registered [ 63.115133] Lustre: Echo OBD driver; http://www.lustre.org/ [ 69.612219] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 70.691739] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 74.108468] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 76.539375] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 79.033688] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 83.844236] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 88.175961] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 88.199135] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 88.207815] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 89.290559] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 89.302331] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 89.341324] Lustre: lustre-MDT0000: new disk, initializing [ 89.364748] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 89.372629] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 90.668651] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 95.686194] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 95.720057] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 95.746220] Lustre: 6487: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 [ 95.759950] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 95.761679] Lustre: Skipped 1 previous similar message [ 95.794528] Lustre: lustre-MDT0001: new disk, initializing [ 95.815295] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 95.823188] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 95.826868] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 97.079979] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 99.243448] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 102.257183] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 102.283461] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 102.376508] Lustre: lustre-OST0000: new disk, initializing [ 102.378608] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 102.396893] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 103.791789] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 103.795613] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 103.825344] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 104.448830] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 109.874906] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 109.902110] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 109.935154] Lustre: lustre-OST0001: new disk, initializing [ 109.937275] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 109.953317] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 112.000838] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 113.262136] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 113.264752] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 113.274356] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 118.088829] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 122.722109] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 129.700976] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing check_logdir /tmp/testlogs/ [ 131.304251] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing yml_node [ 132.717493] Lustre: DEBUG MARKER: Client: 2.16.58.1 [ 133.481898] Lustre: DEBUG MARKER: MDS: 2.16.58.1 [ 134.297733] Lustre: DEBUG MARKER: OSS: 2.16.58.1 [ 134.868566] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Sun Aug 31 17:32:21 EDT 2025 [ 140.490197] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 143.546518] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 146.912751] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 146.916041] 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 [ 146.919748] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 149.473813] 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 [ 149.474191] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 149.481257] Lustre: Skipped 3 previous similar messages [ 151.802582] LustreError: 12548:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 151.828573] Lustre: server umount lustre-MDT0000 complete [ 154.457025] LustreError: 7420:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756675960 with bad export cookie 763471525213428747 [ 154.458821] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 154.459958] LustreError: 7420:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 154.520108] LustreError: 12999:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 154.521834] LustreError: 12999:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 154.587705] Lustre: server umount lustre-MDT0001 complete [ 167.473892] LustreError: 13448:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 167.475836] LustreError: 13448:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 167.491577] Lustre: server umount lustre-OST0000 complete [ 169.937093] Lustre: 3633:0:(client.c:2470:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1756675960/real 1756675960] req@ffffa07734e8b100 x1842008153987200/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1756675976 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 169.946152] 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 [ 169.950248] Lustre: Skipped 2 previous similar messages [ 170.181585] LustreError: 13899:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 170.184141] LustreError: 13899:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 170.242318] Lustre: server umount lustre-OST0001 complete [ 175.288601] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 176.306444] Key type lgssc unregistered [ 176.441393] LNet: 14679:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 176.443790] LNetError: 14679:0:(acceptor.c:263:lnet_acceptor_remove_socket()) Interface ens2 not found [ 176.449468] LNet: Removed LNI 192.168.202.141@tcp [ 176.778127] Key type .llcrypt unregistered [ 176.779803] Key type ._llcrypt unregistered [ 183.958665] Key type ._llcrypt registered [ 183.959745] Key type .llcrypt registered [ 183.999271] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 189.829180] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 190.105286] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 190.147073] alg: No test for adler32 (adler32-zlib) [ 190.987244] Lustre: Lustre: Build Version: 2.16.58_1_g28cf6eb [ 191.063957] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 192.648179] Key type lgssc registered [ 192.986746] Lustre: Echo OBD driver; http://www.lustre.org/ [ 196.111100] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 198.512551] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 200.616566] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 202.930460] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 207.808471] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 211.887678] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 211.905749] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 211.911575] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 213.000213] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 213.012513] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 213.049194] Lustre: lustre-MDT0000: new disk, initializing [ 213.074141] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 213.082192] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 214.481376] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 219.520666] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 219.539867] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 219.562219] Lustre: 19055: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 [ 219.575110] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 219.577427] Lustre: Skipped 1 previous similar message [ 219.577549] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 219.610749] Lustre: lustre-MDT0001: new disk, initializing [ 219.627659] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 219.633582] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 219.638532] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 220.794075] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 223.043681] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 226.304886] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 226.329820] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 226.409864] Lustre: lustre-OST0000: new disk, initializing [ 226.412253] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 226.431790] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 228.332752] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 228.338389] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 228.359194] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 228.500169] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 233.874842] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 233.898585] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 233.930262] Lustre: lustre-OST0001: new disk, initializing [ 233.931858] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 233.947660] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 235.758721] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 235.761479] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 235.778524] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 235.809939] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 241.033859] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 246.528880] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 254.012760] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 17:34:20 (1756676060) === [ 254.896827] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 17:34:21 (1756676061) [ 256.544492] LustreError: 23234:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 3000ms [ 259.560092] LustreError: 23234:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 awake [ 260.144427] LustreError: 23477:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 3000ms [ 260.321874] Lustre: 20956:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 260.324912] Lustre: 23504:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 260.325037] Lustre: 20956:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 1 previous similar message [ 260.329226] Lustre: 23504:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 260.329236] Lustre: 23504:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 260.331629] Lustre: 20956:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 260.334572] Lustre: 23504:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 1 previous similar message [ 260.338623] Lustre: 20956:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 260.351276] Lustre: 20956:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 8 previous similar messages [ 260.769040] LustreError: 23477:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout interrupted [ 262.849363] Lustre: 23518:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 262.851759] Lustre: 23518:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 75 previous similar messages [ 262.853524] Lustre: 23518:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 262.855509] Lustre: 23518:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 76 previous similar messages [ 262.857143] Lustre: 23518:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 262.859130] Lustre: 23518:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 76 previous similar messages [ 262.861363] Lustre: 23518:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 262.863558] Lustre: 23518:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 75 previous similar messages [ 262.866170] Lustre: 23518:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 262.868343] Lustre: 23518:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 76 previous similar messages [ 262.871071] Lustre: 23518:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 262.873399] Lustre: 23518:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 265.697498] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 265.700157] 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 [ 265.704277] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 266.720829] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 266.720839] 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 [ 266.722721] Lustre: Skipped 1 previous similar message [ 266.727019] Lustre: Skipped 1 previous similar message [ 269.689701] LustreError: 23979:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 269.712199] Lustre: server umount lustre-MDT0000 complete [ 270.896575] LustreError: 20005:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756676077 with bad export cookie 9944393410902527331 [ 270.897851] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 270.898987] LustreError: 20005:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 270.957615] LustreError: 24180:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 270.960604] LustreError: 24180:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 271.030767] Lustre: server umount lustre-MDT0001 complete [ 282.417083] LustreError: 24380:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 282.419969] LustreError: 24380:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 282.439077] Lustre: server umount lustre-OST0000 complete [ 292.848642] LustreError: 24582:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 292.850226] LustreError: 24582:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 292.910873] Lustre: server umount lustre-OST0001 complete [ 295.636769] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 17:35:02 (1756676102) [ 300.044707] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 303.185927] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 303.340742] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 304.600414] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 307.429375] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 308.930993] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 309.995281] Lustre: 27056:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 312.386576] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 312.500308] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 312.502974] Lustre: Skipped 1 previous similar message [ 313.506461] LustreError: 27413:0:(ldlm_lib.c:1132: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. [ 313.512160] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 313.513977] LustreError: 27413:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 2 previous similar messages [ 314.515420] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 317.487445] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 318.563743] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 319.324777] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 322.366365] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 323.540324] Lustre: 28902:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 330.024867] Lustre: *** cfs_fail_loc=1501, val=0*** [ 330.030572] Lustre: 28391:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 330.033196] Lustre: 28391:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 330.036629] Lustre: 28391:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 330.039824] Lustre: 28391:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 330.043578] Lustre: 28391:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 330.046947] Lustre: 28391:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 332.201406] Lustre: Failing over lustre-MDT0000 [ 332.261025] LustreError: 29264:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 332.262669] LustreError: 29264:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 332.284112] Lustre: server umount lustre-MDT0000 complete [ 333.280434] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 333.283479] 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 [ 333.287538] Lustre: Skipped 1 previous similar message [ 333.289336] LustreError: 26663:0:(ldlm_lib.c:1132: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. [ 334.305204] LustreError: 26663:0:(ldlm_lib.c:1132: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. [ 334.312305] LustreError: 26663:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 3 previous similar messages [ 335.857697] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 335.892192] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 335.970404] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 335.972687] Lustre: Skipped 1 previous similar message [ 337.354624] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 338.087677] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 338.089951] Lustre: lustre-MDT0000: Denying connection for new client d8eea8d3-30e1-4145-865e-4e2bf54997f9 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 341.479326] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 341.485480] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 341.499199] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 341.499208] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 343.624051] Lustre: *** cfs_fail_loc=1505, val=0*** [ 345.916838] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 17:35:52 (1756676152) [ 347.373313] Lustre: *** cfs_fail_loc=1502, val=0*** [ 347.379257] Lustre: 27412:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 347.382070] Lustre: 27412:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 78 previous similar messages [ 347.383889] Lustre: 27412:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 347.386910] Lustre: 27412:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 347.389032] Lustre: 27412:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 347.390985] Lustre: 27412:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 347.393013] Lustre: 27412:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 347.394754] Lustre: 27412:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 347.396422] Lustre: 27412:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 347.398169] Lustre: 27412:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 347.400436] Lustre: 27412:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 347.403901] Lustre: 27412:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 350.024864] Lustre: Failing over lustre-MDT0000 [ 350.085054] LustreError: 30920:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 350.086761] LustreError: 30920:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 350.109403] Lustre: server umount lustre-MDT0000 complete [ 351.713063] 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 [ 351.713323] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 351.713471] LustreError: 30490:0:(ldlm_lib.c:1132: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. [ 351.717246] Lustre: Skipped 6 previous similar messages [ 353.429922] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 353.462158] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 354.854860] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 355.604439] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 355.608942] Lustre: lustre-MDT0000: Denying connection for new client d6137ec7-eabe-41e3-821e-2131cbc292d8 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 355.616996] Lustre: Skipped 1 previous similar message [ 358.883786] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 358.886389] Lustre: Skipped 3 previous similar messages [ 358.892100] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 358.908398] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 358.908465] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 361.027679] Lustre: *** cfs_fail_loc=1505, val=0*** [ 363.440134] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 17:36:09 (1756676169) [ 364.892117] Lustre: *** cfs_fail_loc=1504, val=0*** [ 364.898326] Lustre: 28391:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 364.901654] Lustre: 28391:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 78 previous similar messages [ 364.904195] Lustre: 28391:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 364.906172] Lustre: 28391:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 364.908427] Lustre: 28391:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 364.910709] Lustre: 28391:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 364.912860] Lustre: 28391:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 364.915063] Lustre: 28391:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 364.917471] Lustre: 28391:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 364.919134] Lustre: 28391:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 364.921133] Lustre: 28391:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 364.923391] Lustre: 28391:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 367.156637] Lustre: Failing over lustre-MDT0000 [ 367.233650] LustreError: 32473:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 367.236154] LustreError: 32473:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 367.267638] Lustre: server umount lustre-MDT0000 complete [ 369.121115] 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 [ 369.121332] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 369.121488] LustreError: 25942:0:(ldlm_lib.c:1132: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. [ 369.121497] LustreError: 25942:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 3 previous similar messages [ 369.126486] Lustre: Skipped 1 previous similar message [ 370.901812] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 370.935655] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 371.018813] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 371.021900] Lustre: Skipped 1 previous similar message [ 372.435863] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 373.187198] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 373.189976] Lustre: lustre-MDT0000: Denying connection for new client 9949285d-52de-46d9-a59d-6bb42e688c50 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 373.196102] Lustre: Skipped 1 previous similar message [ 376.290694] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 376.292846] Lustre: Skipped 3 previous similar messages [ 376.297462] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 376.316576] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 376.316592] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 378.960925] Lustre: *** cfs_fail_loc=1505, val=0*** [ 378.962135] Lustre: Skipped 2 previous similar messages [ 381.441631] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 17:36:27 (1756676187) [ 382.912729] Lustre: *** cfs_fail_loc=1603, val=0*** [ 382.918523] Lustre: 27410:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 382.921541] Lustre: 27410:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 78 previous similar messages [ 382.924709] Lustre: 27410:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 382.927890] Lustre: 27410:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 382.930932] Lustre: 27410:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 382.933108] Lustre: 27410:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 382.934932] Lustre: 27410:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 382.937591] Lustre: 27410:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 382.942164] Lustre: 27410:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 382.946916] Lustre: 27410:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 382.950473] Lustre: 27410:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 382.954925] Lustre: 27410:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 385.347530] Lustre: Failing over lustre-MDT0000 [ 385.433197] Lustre: server umount lustre-MDT0000 complete [ 386.528793] 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 [ 386.528956] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 386.529108] LustreError: 26663:0:(ldlm_lib.c:1132: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. [ 386.529120] LustreError: 26663:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 3 previous similar messages [ 386.532157] Lustre: Skipped 4 previous similar messages [ 388.928970] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 388.965177] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 390.321981] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 391.069714] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 391.073263] Lustre: lustre-MDT0000: Denying connection for new client 1362b261-f166-4fc7-ad43-6153aaa21714 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 391.078228] Lustre: Skipped 1 previous similar message [ 394.210097] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 394.211741] Lustre: Skipped 3 previous similar messages [ 394.221783] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 394.239352] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:298 to 0x2c0000401:321) [ 394.239370] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 398.835922] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 17:36:45 (1756676205) [ 400.193775] Lustre: *** cfs_fail_loc=1604, val=0*** [ 400.200447] Lustre: 27586:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 400.204759] Lustre: 27586:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 78 previous similar messages [ 400.206441] Lustre: 27586:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 400.207980] Lustre: 27586:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 400.209860] Lustre: 27586:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 400.211507] Lustre: 27586:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 400.213289] Lustre: 27586:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 400.215387] Lustre: 27586:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 400.217747] Lustre: 27586:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 400.219529] Lustre: 27586:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 400.221920] Lustre: 27586:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 400.223948] Lustre: 27586:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 78 previous similar messages [ 402.239316] Lustre: Failing over lustre-MDT0000 [ 402.294613] LustreError: 35481:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 402.296151] LustreError: 35481:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 402.319173] Lustre: server umount lustre-MDT0000 complete [ 404.449369] 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 [ 404.449624] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 404.449748] LustreError: 25943:0:(ldlm_lib.c:1132: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. [ 404.449761] LustreError: 25943:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 3 previous similar messages [ 404.452942] Lustre: Skipped 2 previous similar messages [ 405.589300] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 405.619959] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 406.928714] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 407.619151] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 407.621936] Lustre: lustre-MDT0000: Denying connection for new client c6901bde-f9b9-4f39-8f56-8f1ea9210439 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 407.626857] Lustre: Skipped 1 previous similar message [ 411.105856] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 411.108630] Lustre: Skipped 3 previous similar messages [ 411.117203] Lustre: lustre-MDT0000: Recovery over after 0:04, of 1 clients 1 recovered and 0 were evicted. [ 411.131878] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:362 to 0x2c0000401:385) [ 411.131877] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 414.886475] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 17:37:01 (1756676221) [ 416.251219] Lustre: *** cfs_fail_loc=1605, val=0*** [ 418.337802] Lustre: Failing over lustre-MDT0000 [ 418.419464] Lustre: server umount lustre-MDT0000 complete [ 421.345576] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 421.619816] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 421.648366] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 423.017791] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 423.718470] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 423.721243] Lustre: lustre-MDT0000: Denying connection for new client db9b47f5-d011-4c04-89d0-ad841e5880a6 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 423.725478] Lustre: Skipped 1 previous similar message [ 426.978032] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 426.980348] Lustre: Skipped 3 previous similar messages [ 426.990615] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 427.005607] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:426 to 0x280000401:449) [ 427.005623] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 430.973863] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 17:37:17 (1756676237) [ 432.607747] Lustre: *** cfs_fail_loc=161d, val=0*** [ 432.614260] Lustre: 27412:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 432.617877] Lustre: 27412:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 157 previous similar messages [ 432.620848] Lustre: 27412:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 432.624526] Lustre: 27412:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 432.627727] Lustre: 27412:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 432.629958] Lustre: 27412:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 432.632752] Lustre: 27412:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 432.634980] Lustre: 27412:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 432.637203] Lustre: 27412:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 432.639217] Lustre: 27412:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 432.641543] Lustre: 27412:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 432.644256] Lustre: 27412:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 157 previous similar messages [ 434.929880] Lustre: Failing over lustre-MDT0000 [ 435.023925] Lustre: server umount lustre-MDT0000 complete [ 437.216992] 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 [ 437.217433] LustreError: 25948:0:(ldlm_lib.c:1132: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. [ 437.220252] Lustre: Skipped 9 previous similar messages [ 437.224224] LustreError: 25948:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 9 previous similar messages [ 438.702222] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 438.818633] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 438.820863] Lustre: Skipped 3 previous similar messages [ 440.270359] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 441.082818] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 441.085788] Lustre: lustre-MDT0000: Denying connection for new client 84ee9040-bd85-4cd0-9e6f-42b381829622 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 441.089354] Lustre: Skipped 1 previous similar message [ 443.879789] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 443.881568] Lustre: Skipped 3 previous similar messages [ 443.886218] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 443.901637] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 443.901644] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:490 to 0x280000401:513) [ 448.469402] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 17:37:34 (1756676254) [ 449.082985] Lustre: *** cfs_fail_loc=1603, val=0*** [ 452.232267] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 17:37:38 (1756676258) [ 453.618691] Lustre: *** cfs_fail_loc=1603, val=0*** [ 453.925714] Lustre: *** cfs_fail_loc=1604, val=0*** [ 457.372920] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 17:37:43 (1756676263) [ 489.262726] Lustre: Failing over lustre-MDT0000 [ 489.328740] LustreError: 40616:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 489.331817] LustreError: 40616:0:(obd_class.h:479:obd_check_dev()) Skipped 23 previous similar messages [ 489.359812] Lustre: server umount lustre-MDT0000 complete [ 489.953565] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 489.956481] LustreError: Skipped 1 previous similar message [ 491.211293] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 494.101867] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 494.451751] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 498.327333] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 498.333459] Lustre: lustre-MDT0000: reset Object Index mappings [ 498.367996] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 498.372310] LustreError: Skipped 1 previous similar message [ 499.781528] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 501.130877] LustreError: 42380:0:(lfsck_engine.c:1045:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 501.139063] LustreError: 42380:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 502.184066] LustreError: 42380:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 503.224147] LustreError: 42380:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 503.227403] LustreError: 42380:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 503.229832] LustreError: 42380:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 1 previous similar message [ 503.440103] LustreError: 42380:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout interrupted [ 503.777823] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 503.778960] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 503.784365] Lustre: Skipped 3 previous similar messages [ 503.792718] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 503.812236] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:593 to 0x2c0000401:609) [ 503.812239] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:593 to 0x280000401:609) [ 505.048830] Lustre: Failing over lustre-MDT0000 [ 505.125563] Lustre: server umount lustre-MDT0000 complete [ 508.329650] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 508.403244] 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 [ 508.407763] Lustre: Skipped 6 previous similar messages [ 509.597165] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 510.251550] Lustre: lustre-MDT0000: Denying connection for new client 2a106694-58ca-43ec-a0a8-3fd8fd84461c (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 510.257622] Lustre: Skipped 1 previous similar message [ 513.526837] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:593 to 0x2c0000401:641) [ 513.526873] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:593 to 0x280000401:641) [ 515.642980] Lustre: *** cfs_fail_loc=1505, val=0*** [ 517.919414] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 17:38:44 (1756676324) [ 518.551847] Lustre: *** cfs_fail_loc=1504, val=0*** [ 519.308719] Lustre: 40506:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 519.312048] Lustre: 40506:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 229 previous similar messages [ 519.314677] Lustre: 40506:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 519.316848] Lustre: 40506:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 229 previous similar messages [ 519.319255] Lustre: 40506:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 519.322642] Lustre: 40506:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 229 previous similar messages [ 519.326359] Lustre: 40506:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 519.330119] Lustre: 40506:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 229 previous similar messages [ 519.332881] Lustre: 40506:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 519.335316] Lustre: 40506:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 229 previous similar messages [ 519.337704] Lustre: 40506:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 519.340880] Lustre: 40506:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 229 previous similar messages [ 520.491759] Lustre: Failing over lustre-MDT0000 [ 520.569188] Lustre: server umount lustre-MDT0000 complete [ 522.266698] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 523.745365] LustreError: 25948:0:(ldlm_lib.c:1132: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. [ 523.752250] LustreError: 25948:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 12 previous similar messages [ 525.328441] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 525.676475] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 529.375312] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 529.382909] Lustre: lustre-MDT0000: reset Object Index mappings [ 530.812086] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 532.127916] LustreError: 46038:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 533.168110] LustreError: 46038:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 534.516407] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 534.516427] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:682 to 0x280000401:705) [ 537.328133] LustreError: 46038:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 537.330907] LustreError: 46038:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 3 previous similar messages [ 538.377129] LustreError: 46038:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout interrupted [ 539.900192] Lustre: Failing over lustre-MDT0000 [ 539.992698] Lustre: server umount lustre-MDT0000 complete [ 543.658683] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 545.183993] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 548.850234] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 548.850248] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:682 to 0x280000401:737) [ 551.486407] Lustre: *** cfs_fail_loc=1505, val=0*** [ 551.487697] Lustre: Skipped 85 previous similar messages [ 553.965792] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 17:39:20 (1756676360) [ 555.856991] LustreError: 47940:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 1000ms [ 555.862493] LustreError: 47940:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) Skipped 5 previous similar messages [ 556.904098] LustreError: 47940:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 awake [ 560.024124] Lustre: *** cfs_fail_loc=1608, val=1*** [ 562.873043] LustreError: 48283:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout interrupted [ 565.065312] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 17:39:31 (1756676371) [ 572.048175] LustreError: 48771:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 1000ms [ 572.050440] LustreError: 48771:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 9 previous similar messages [ 573.096101] LustreError: 48771:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 573.098644] LustreError: 48771:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 8 previous similar messages [ 573.100842] Lustre: *** cfs_fail_loc=1609, val=1*** [ 576.584049] LustreError: 49164:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout interrupted [ 578.837385] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 17:39:45 (1756676385) [ 584.859199] Lustre: Failing over lustre-MDT0000 [ 585.195317] Lustre: server umount lustre-MDT0000 complete [ 588.154472] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 588.184881] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 588.187586] LustreError: Skipped 3 previous similar messages [ 588.255577] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 588.257124] Lustre: Skipped 4 previous similar messages [ 589.492736] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 593.376601] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 593.377823] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 593.378634] Lustre: Skipped 3 previous similar messages [ 593.381441] Lustre: Skipped 15 previous similar messages [ 593.391155] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 593.392902] Lustre: Skipped 3 previous similar messages [ 593.406411] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:855 to 0x280000401:897) [ 593.406628] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:855 to 0x2c0000401:897) [ 596.388100] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 17:40:02 (1756676402) [ 600.717512] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 606.323228] Lustre: 52594:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 614.421700] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 615.599187] Lustre: 53727:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 622.141943] Lustre: *** cfs_fail_loc=1604, val=0*** [ 622.143622] Lustre: Skipped 82 previous similar messages [ 623.044878] LustreError: 53880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout id 1602 sleeping for 1000ms [ 623.049600] LustreError: 53880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 6 previous similar messages [ 624.088053] LustreError: 53880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout id 1602 awake [ 624.090722] LustreError: 53880:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 5 previous similar messages [ 624.242030] Lustre: Failing over lustre-MDT0000 [ 626.257612] LustreError: 54028:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 626.259375] LustreError: 54028:0:(obd_class.h:479:obd_check_dev()) Skipped 39 previous similar messages [ 626.290953] Lustre: server umount lustre-MDT0000 complete [ 629.217483] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 629.220297] LustreError: Skipped 1 previous similar message [ 629.444409] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 629.618846] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 630.931975] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 634.872570] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:947 to 0x2c0000401:993) [ 634.872575] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 637.998327] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 17:40:44 (1756676444) [ 639.968951] 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 [ 639.972127] Lustre: Skipped 17 previous similar messages [ 639.973651] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 639.975766] Lustre: Skipped 5 previous similar messages [ 644.888200] Lustre: server umount lustre-MDT0000 complete [ 646.135872] LustreError: 29265:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756676452 with bad export cookie 9944393410902743813 [ 646.140130] LustreError: 29265:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 646.286767] Lustre: server umount lustre-MDT0001 complete [ 657.409064] Lustre: server umount lustre-OST0000 complete [ 669.106240] Lustre: server umount lustre-OST0001 complete [ 671.203607] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 673.504685] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 676.920088] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 679.167306] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 681.252397] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 683.251873] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 687.684307] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 691.298295] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 691.319518] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 691.415973] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 691.428069] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 691.465135] Lustre: lustre-MDT0000: new disk, initializing [ 691.497198] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 692.863515] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 697.081499] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 697.108374] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 697.135275] Lustre: 58872: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 [ 697.206955] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 698.484373] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 700.759962] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 703.001543] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 703.029917] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 703.102726] Lustre: lustre-OST0000: new disk, initializing [ 703.104015] Lustre: Skipped 1 previous similar message [ 703.105371] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 703.106916] Lustre: Skipped 2 previous similar messages [ 703.921502] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 703.925920] Lustre: Skipped 1 previous similar message [ 703.927754] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 703.955376] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 705.071203] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 709.127940] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 709.150555] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 710.523631] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 711.037567] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 715.348063] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 716.475873] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 723.714587] Lustre: *** cfs_fail_loc=1603, val=0*** [ 724.001120] Lustre: *** cfs_fail_loc=1604, val=0*** [ 724.002241] Lustre: Skipped 19 previous similar messages [ 724.008163] Lustre: 60456:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 724.010453] Lustre: 60456:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 332 previous similar messages [ 724.012555] Lustre: 60456:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 724.014235] Lustre: 60456:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 332 previous similar messages [ 724.016078] Lustre: 60456:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 724.018085] Lustre: 60456:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 332 previous similar messages [ 724.019861] Lustre: 60456:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 724.021808] Lustre: 60456:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 332 previous similar messages [ 724.023661] Lustre: 60456:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 724.025502] Lustre: 60456:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 332 previous similar messages [ 724.027307] Lustre: 60456:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 724.029241] Lustre: 60456:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 332 previous similar messages [ 725.033251] LustreError: 62341:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 sleeping for 2000ms [ 725.036369] LustreError: 62341:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 2 previous similar messages [ 727.120092] LustreError: 62341:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) cfs_fail_timeout id 1601 awake [ 727.122564] LustreError: 62341:0:(lfsck_engine.c:685:lfsck_master_dir_engine()) Skipped 2 previous similar messages [ 729.809098] Lustre: *** cfs_fail_loc=1609, val=2*** [ 732.600116] Lustre: *** cfs_fail_loc=160a, val=2*** [ 736.700982] Lustre: Failing over lustre-MDT0000 [ 736.793792] Lustre: server umount lustre-MDT0000 complete [ 738.272595] LustreError: 58883:0:(ldlm_lib.c:1132:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 738.276938] LustreError: 58883:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 12 previous similar messages [ 739.841090] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 739.878348] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 739.881398] LustreError: Skipped 2 previous similar messages [ 739.979739] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 741.241468] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 743.938464] Lustre: Failing over lustre-MDT0000 [ 745.133700] LustreError: 64238:0:(ldlm_lib.c:2935:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 745.142588] Lustre: 63557:0:(ldlm_lib.c:2338:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 745.147958] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 745.152048] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 745.163849] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 745.172562] LustreError: 63557:0:(client.c:1371:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffffa07738b89880 x1842008291288576/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 [ 745.185824] LustreError: 63557:0:(fid_request.c:213:seq_client_alloc_seq()) cli-cli-lustre-MDT0001-osp-MDT0000: Cannot allocate new meta-sequence: rc = -5 [ 745.192441] LustreError: 63557:0:(fid_request.c:316:seq_client_alloc_fid()) cli-cli-lustre-MDT0001-osp-MDT0000: Can't allocate new sequence: rc = -5 [ 745.330838] Lustre: server umount lustre-MDT0000 complete [ 748.683534] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 748.840981] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 748.842941] Lustre: Skipped 1 previous similar message [ 750.100639] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 752.212562] Lustre: Failing over lustre-MDT0000 [ 752.215956] LustreError: 65300:0:(ldlm_lib.c:2935:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 752.217939] Lustre: 64767:0:(ldlm_lib.c:2338:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 752.219971] Lustre: 64767:0:(ldlm_lib.c:2338:target_recovery_overseer()) Skipped 2 previous similar messages [ 752.221871] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000bd0:0x1:0x0] [ 752.227701] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 752.230828] LustreError: 64767:0:(client.c:1371:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffffa0773ed3d180 x1842008291300992/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 [ 752.235274] LustreError: 64767:0:(fid_request.c:213:seq_client_alloc_seq()) cli-cli-lustre-MDT0001-osp-MDT0000: Cannot allocate new meta-sequence: rc = -5 [ 752.237743] LustreError: 64767:0:(fid_request.c:316:seq_client_alloc_fid()) cli-cli-lustre-MDT0001-osp-MDT0000: Can't allocate new sequence: rc = -5 [ 752.251850] Lustre: *** cfs_fail_loc=160b, val=2*** [ 752.330266] Lustre: server umount lustre-MDT0000 complete [ 755.969973] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 756.142147] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 756.143731] Lustre: Skipped 2 previous similar messages [ 757.460519] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 760.584055] LustreError: 66315:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout interrupted [ 761.312980] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 761.314319] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 761.315298] Lustre: Skipped 1 previous similar message [ 761.317039] Lustre: Skipped 7 previous similar messages [ 761.323455] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 761.326354] Lustre: Skipped 1 previous similar message [ 761.343799] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:65) [ 761.343815] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 763.140934] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 17:42:49 (1756676569) [ 767.519383] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 773.351416] Lustre: 68190:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 781.523228] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 827.451155] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 17:43:53 (1756676633) [ 836.870148] Lustre: *** cfs_fail_loc=1604, val=0*** [ 836.871234] Lustre: Skipped 4 previous similar messages [ 841.686215] Lustre: *** cfs_fail_loc=160c, val=0*** [ 841.687725] Lustre: Skipped 1 previous similar message [ 866.663455] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 17:44:33 (1756676673) [ 875.540358] Lustre: *** cfs_fail_loc=1603, val=0*** [ 883.549088] Lustre: *** cfs_fail_loc=1603, val=0*** [ 883.550525] Lustre: Skipped 1835 previous similar messages [ 947.840207] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 17:45:54 (1756676754) [ 981.473469] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 981.473635] 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 [ 981.474514] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 981.476121] LustreError: Skipped 2 previous similar messages [ 981.479046] Lustre: Skipped 10 previous similar messages [ 987.072478] LustreError: 72055:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 987.074369] LustreError: 72055:0:(obd_class.h:479:obd_check_dev()) Skipped 57 previous similar messages [ 987.121793] Lustre: server umount lustre-MDT0000 complete [ 988.332659] LustreError: 62079:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756676794 with bad export cookie 9944393410902762342 [ 988.335728] LustreError: 62079:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 988.472843] Lustre: server umount lustre-MDT0001 complete [ 999.942881] Lustre: server umount lustre-OST0000 complete [ 1011.444562] Lustre: server umount lustre-OST0001 complete [ 1013.598504] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 1016.311622] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1033.824290] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 1039.968203] LustreError: 73454:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.141@tcp: failed processing log, type 4: rc = -110 [ 1068.640215] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1068.641968] Lustre: Skipped 8 previous similar messages [ 1070.477946] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1071.676923] Lustre: 74021: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. [ 1071.684326] Lustre: *** cfs_fail_loc=160e, val=3*** [ 1074.723257] Lustre: 74021:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1077.624850] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 17:48:03 (1756676883) [ 1082.278964] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1085.742954] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1085.875696] LustreError: 73480:0:(ldlm_lib.c:1132: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. [ 1085.883216] LustreError: 73480:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 8 previous similar messages [ 1085.920060] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3209 to 0x280000401:3233) [ 1087.146512] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1089.954222] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1091.313134] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1092.238346] Lustre: 76687:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1092.241990] Lustre: 76687:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 1097.222734] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1098.613688] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3144 to 0x2c0000401:3169) [ 1099.267457] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1102.476315] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1110.072298] Lustre: *** cfs_fail_loc=160d, val=0*** [ 1111.751147] Lustre: Failing over lustre-OST0000 [ 1111.783773] Lustre: server umount lustre-OST0000 complete [ 1114.872145] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1114.920988] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1116.650944] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1116.656519] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1116.657525] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1116.658148] Lustre: *** cfs_fail_loc=215, val=0*** [ 1116.664242] Lustre: Skipped 3 previous similar messages [ 1116.726600] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1117.990273] Lustre: 79564: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. [ 1117.996165] Lustre: 79564:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1118.894309] Lustre: Failing over lustre-OST0000 [ 1118.928056] Lustre: server umount lustre-OST0000 complete [ 1121.821284] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1123.769983] Lustre: *** cfs_fail_loc=215, val=0*** [ 1123.772536] Lustre: Skipped 3 previous similar messages [ 1123.790388] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1125.856752] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1125.859180] Lustre: Skipped 7 previous similar messages [ 1131.796107] Lustre: server umount lustre-MDT0000 complete [ 1133.019772] LustreError: 78436:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756676939 with bad export cookie 9944393410904308362 [ 1133.021055] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1133.023894] LustreError: 78436:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1133.026679] LustreError: Skipped 3 previous similar messages [ 1133.167919] Lustre: server umount lustre-MDT0001 complete [ 1144.314385] Lustre: server umount lustre-OST0000 complete [ 1154.804165] Lustre: server umount lustre-OST0001 complete [ 1157.781872] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 17:49:24 (1756676964) [ 1162.358857] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1165.867364] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1167.308293] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1170.110978] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1171.485891] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1172.427767] Lustre: 83881:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1172.430453] Lustre: 83881:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 1174.595231] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1175.715323] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3298 to 0x280000401:3329) [ 1176.503373] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1179.317844] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1180.387858] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3144 to 0x2c0000401:3201) [ 1181.261889] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1184.372996] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1199.784562] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 17:50:06 (1756677006) [ 1204.027609] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 17:50:10 (1756677010) [ 1204.423352] Lustre: *** cfs_fail_loc=160f, val=0*** [ 1207.812641] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 17:50:14 (1756677014) [ 1208.850736] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1208.852908] Lustre: Skipped 7 previous similar messages [ 1212.820180] Lustre: 82775:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 260, rollback = 2 [ 1212.826066] Lustre: 82775:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 1239 previous similar messages [ 1212.830090] Lustre: 82775:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 1212.832571] Lustre: 82775:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 1239 previous similar messages [ 1212.834990] Lustre: 82775:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 1212.837789] Lustre: 82775:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 1239 previous similar messages [ 1212.840928] Lustre: 82775:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 1212.844395] Lustre: 82775:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 1239 previous similar messages [ 1212.849177] Lustre: 82775:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 1/17/0, delete: 0/0/0 [ 1212.851900] Lustre: 82775:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 1239 previous similar messages [ 1212.855649] Lustre: 82775:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1212.858440] Lustre: 82775:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 1239 previous similar messages [ 1245.153069] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1245.154905] Lustre: Skipped 7 previous similar messages [ 1250.871747] Lustre: server umount lustre-MDT0000 complete [ 1252.255723] LustreError: 82754:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756677058 with bad export cookie 9944393410904317091 [ 1252.259822] LustreError: 82754:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1252.418955] Lustre: server umount lustre-MDT0001 complete [ 1264.640626] Lustre: server umount lustre-OST0000 complete [ 1276.328725] Lustre: server umount lustre-OST0001 complete [ 1281.352148] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1285.064131] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1286.521909] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1289.395411] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1290.756953] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1293.847681] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1294.947245] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3490 to 0x280000401:3521) [ 1295.850838] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1298.753082] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1299.811544] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 1299.812400] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3253 to 0x2c0000401:3297) [ 1299.830146] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 1300.730974] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1303.788267] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1305.014988] Lustre: 93404:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1305.017940] Lustre: 93404:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 2 previous similar messages [ 1312.076277] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 17:51:58 (1756677118) [ 1313.448690] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1313.449972] Lustre: Skipped 63 previous similar messages [ 1351.137620] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1351.137683] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1351.139641] LustreError: Skipped 1 previous similar message [ 1351.141437] Lustre: Skipped 7 previous similar messages [ 1356.894658] Lustre: server umount lustre-MDT0000 complete [ 1358.224720] LustreError: 90430:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756677164 with bad export cookie 9944393410904345511 [ 1358.227955] LustreError: 90430:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1358.377700] Lustre: server umount lustre-MDT0001 complete [ 1370.626241] Lustre: server umount lustre-OST0000 complete [ 1382.263741] Lustre: server umount lustre-OST0001 complete [ 1387.862406] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1391.530897] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1393.128262] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1396.056783] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1397.457656] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1400.674745] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1401.828833] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3618 to 0x280000401:3649) [ 1402.821685] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1405.686912] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1406.756909] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 1406.757714] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3253 to 0x2c0000401:3329) [ 1406.758532] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 1407.701794] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1410.887610] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1419.298679] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 17:53:45 (1756677225) [ 1420.178303] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1420.179499] Lustre: Skipped 63 previous similar messages [ 1420.239221] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1423.617492] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 17:53:50 (1756677230) [ 1424.285803] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1424.305101] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1424.306316] Lustre: Skipped 3 previous similar messages [ 1427.688197] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 17:53:54 (1756677234) [ 1428.245131] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 1428.880358] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 17:53:55 (1756677235) [ 1431.874285] Lustre: *** cfs_fail_loc=1709, val=0*** [ 1431.995121] LustreError: 101642:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200003ab2:0x1:0x0]: rc = -5 [ 1431.998541] LustreError: 101642:0:(mdt_reint.c:2564:mdt_reint_migrate()) lustre-MDT0001: migrate [0x240002340:0x6c:0x0]/s57 failed: rc = -5 [ 1436.334310] LustreError: 97480:0:(lod_object.c:930:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x51:0x0]:1 for the striped directory [0x240002340:0xd4:0x0] is out of the known LMV EA range [0 - 0], failout [ 1437.449332] LustreError: 100458:0:(lod_object.c:930:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x51:0x0]:1 for the striped directory [0x240002340:0xd4:0x0] is out of the known LMV EA range [0 - 0], failout [ 1437.455068] LustreError: 100458:0:(mdt_handler.c:1501:mdt_getattr_internal()) lustre-MDT0001: getattr error for [0x240002340:0xd4:0x0]: rc = -5 [ 1472.992693] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1472.994322] Lustre: Skipped 4 previous similar messages [ 1475.985764] Lustre: server umount lustre-MDT0000 complete [ 1478.675605] LustreError: 101948:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756677284 with bad export cookie 9944393410904360239 [ 1478.678883] LustreError: 101948:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1478.800286] Lustre: server umount lustre-MDT0001 complete [ 1490.944558] Lustre: server umount lustre-OST0000 complete [ 1503.984406] LustreError: 103413:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 1503.987149] LustreError: 103413:0:(obd_class.h:479:obd_check_dev()) Skipped 131 previous similar messages [ 1504.048417] Lustre: server umount lustre-OST0001 complete [ 1509.684024] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 1510.796630] Key type lgssc unregistered [ 1510.944323] LNet: 104244:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 1510.946521] LNetError: 104244:0:(acceptor.c:263:lnet_acceptor_remove_socket()) Interface ens2 not found [ 1510.952378] LNet: Removed LNI 192.168.202.141@tcp [ 1511.302112] Key type .llcrypt unregistered [ 1511.303115] Key type ._llcrypt unregistered [ 1518.892070] Key type ._llcrypt registered [ 1518.893065] Key type .llcrypt registered [ 1518.930722] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 1524.447590] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1524.874975] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 1524.885083] alg: No test for adler32 (adler32-zlib) [ 1525.740847] Lustre: Lustre: Build Version: 2.16.58_1_g28cf6eb [ 1525.825685] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 1527.408173] Key type lgssc registered [ 1527.757835] Lustre: Echo OBD driver; http://www.lustre.org/ [ 1530.969384] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1533.468589] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1535.869289] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1538.281064] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1543.038136] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1547.281346] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1547.300374] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 1547.305743] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1548.387550] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1548.398533] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1548.433839] Lustre: lustre-MDT0000: new disk, initializing [ 1548.457871] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1548.464334] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1549.753661] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1554.880761] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1554.902943] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1554.923654] Lustre: 108623: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 [ 1554.934175] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1554.935610] Lustre: Skipped 1 previous similar message [ 1554.969861] Lustre: lustre-MDT0001: new disk, initializing [ 1554.987139] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1554.993640] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1554.996818] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1556.190063] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1558.562726] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1561.837124] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1561.862050] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1561.940174] Lustre: lustre-OST0000: new disk, initializing [ 1561.943275] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1561.960563] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1563.925618] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1564.909670] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1564.914498] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1564.936370] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1569.141513] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1569.174413] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1569.212078] Lustre: lustre-OST0001: new disk, initializing [ 1569.214518] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1569.234502] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 1571.211154] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1574.890554] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1574.892749] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1574.911541] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1576.677732] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1583.380801] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1590.169874] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 17:56:36 (1756677396) === [ 1592.321367] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 17:56:38 (1756677398) [ 1592.474359] Lustre: 110524:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 1592.477750] Lustre: 110524:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1592.479720] Lustre: 110524:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 1592.484183] Lustre: 110524:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 1592.486128] Lustre: 110524:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1592.487819] Lustre: 110524:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1593.110499] Lustre: *** cfs_fail_loc=1613, val=0*** [ 1596.181618] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 17:56:42 (1756677402) [ 1596.720319] Lustre: *** cfs_fail_loc=1614, val=0*** [ 1596.757904] Lustre: 110524:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 1596.761026] Lustre: 110524:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1596.762870] Lustre: 110524:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 1596.764775] Lustre: 110524:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 1596.766946] Lustre: 110524:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1596.768862] Lustre: 110524:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1598.015052] Lustre: 110524:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 1598.020033] Lustre: 110524:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1598.023052] Lustre: 110524:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 1598.025168] Lustre: 110524:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1598.027124] Lustre: 110524:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1598.029973] Lustre: 110524:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1600.073775] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 17:56:46 (1756677406) [ 1600.428554] Lustre: 110524:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 275, rollback = 2 [ 1600.431138] Lustre: 110524:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 1 previous similar message [ 1600.433092] Lustre: 110524:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1600.435559] Lustre: 110524:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1600.438878] Lustre: 110524:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/275/0 [ 1600.441698] Lustre: 110524:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1600.445818] Lustre: 110524:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1600.448655] Lustre: 110524:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1600.451389] Lustre: 110524:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1600.453496] Lustre: 110524:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1600.456441] Lustre: 110524:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1600.458479] Lustre: 110524:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 1 previous similar message [ 1600.893552] Lustre: *** cfs_fail_loc=1615, val=0*** [ 1600.894730] Lustre: Skipped 1 previous similar message [ 1604.258827] LustreError: 113845: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 [ 1608.230198] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 1608.795505] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 17:56:55 (1756677415) [ 1609.536936] Lustre: *** cfs_fail_loc=1617, val=0*** [ 1609.558076] Lustre: *** cfs_fail_loc=1617, val=0*** [ 1610.249694] Lustre: *** cfs_fail_loc=1616, val=0*** [ 1610.251188] Lustre: Skipped 5 previous similar messages [ 1617.552402] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 17:57:03 (1756677423) [ 1617.744251] Lustre: 113411:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 1617.746660] Lustre: 113411:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 4 previous similar messages [ 1617.748460] Lustre: 113411:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1617.750223] Lustre: 113411:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1617.752210] Lustre: 113411:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 1617.754050] Lustre: 113411:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1617.755908] Lustre: 113411:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1617.757864] Lustre: 113411:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1617.759763] Lustre: 113411:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1617.761715] Lustre: 113411:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1617.763657] Lustre: 113411:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1617.765405] Lustre: 113411:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 4 previous similar messages [ 1618.175751] Lustre: *** cfs_fail_loc=1618, val=0*** [ 1618.177083] Lustre: Skipped 5 previous similar messages [ 1651.680614] 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 [ 1651.681570] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1651.686387] Lustre: Skipped 2 previous similar messages [ 1651.687910] Lustre: Skipped 1 previous similar message [ 1655.613432] LustreError: 115440:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 1655.642538] Lustre: server umount lustre-MDT0000 complete [ 1656.807550] LustreError: 108615:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756677463 with bad export cookie 7260563916237008076 [ 1656.808730] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1656.813573] LustreError: 108615:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1656.880680] LustreError: 115641:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 1656.882229] LustreError: 115641:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1656.951688] Lustre: server umount lustre-MDT0001 complete [ 1668.081517] LustreError: 115841:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 1668.083134] LustreError: 115841:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1668.097837] Lustre: server umount lustre-OST0000 complete [ 1679.472134] LustreError: 116043:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 1679.473792] LustreError: 116043:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1679.539324] Lustre: server umount lustre-OST0001 complete [ 1684.569341] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1688.027665] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1688.156796] LustreError: 117215:0:(ldlm_lib.c:1132: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. [ 1688.162030] LustreError: 117215:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 5 previous similar messages [ 1688.174235] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1689.460363] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1692.354290] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1693.653518] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1694.583309] Lustre: 118322:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1696.754946] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1696.852263] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1696.855334] Lustre: Skipped 1 previous similar message [ 1697.889862] LustreError: 118679:0:(ldlm_lib.c:1132: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. [ 1697.894254] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 1698.808252] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1701.655385] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1702.755699] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 1702.756100] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 1702.756684] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 1703.598729] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1706.730731] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1707.886789] Lustre: 120171:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1717.460242] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 17:58:43 (1756677523) [ 1717.651384] Lustre: 120544:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 1717.654113] Lustre: 120544:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 3 previous similar messages [ 1717.656027] Lustre: 120544:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1717.659120] Lustre: 120544:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1717.661453] Lustre: 120544:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 1717.663628] Lustre: 120544:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1717.665761] Lustre: 120544:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1717.668151] Lustre: 120544:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1717.670253] Lustre: 120544:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1717.672282] Lustre: 120544:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1717.674356] Lustre: 120544:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1717.676457] Lustre: 120544:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1718.069599] Lustre: *** cfs_fail_loc=1618, val=0*** [ 1718.070825] Lustre: Skipped 3 previous similar messages [ 1754.080935] 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 [ 1754.081148] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1754.081489] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1754.081494] Lustre: Skipped 2 previous similar messages [ 1754.085910] Lustre: Skipped 3 previous similar messages [ 1755.397986] LustreError: 120947:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1755.402789] LustreError: 120947:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 1755.437370] Lustre: server umount lustre-MDT0000 complete [ 1756.665784] LustreError: 117195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756677562 with bad export cookie 7260563916237023266 [ 1756.667597] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1756.670238] LustreError: 117195:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1756.843313] Lustre: server umount lustre-MDT0001 complete [ 1768.433801] LustreError: 121348:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 1768.435855] LustreError: 121348:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 1768.453436] Lustre: server umount lustre-OST0000 complete [ 1780.292227] Lustre: server umount lustre-OST0001 complete [ 1786.187544] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1789.893863] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1790.052935] LustreError: 122721:0:(ldlm_lib.c:1132: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. [ 1790.074608] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1790.077239] Lustre: Skipped 1 previous similar message [ 1791.389580] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1794.231202] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1795.548339] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1796.490910] Lustre: 123830:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1798.735998] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1799.905521] LustreError: 124186:0:(ldlm_lib.c:1132: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. [ 1799.907879] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 1800.784792] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1803.601228] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1804.710472] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 1804.711283] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 1804.716782] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 1805.679823] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1808.756124] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1809.977275] Lustre: 125677:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1816.733385] Lustre: 122720:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 1816.735787] Lustre: 122720:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 3 previous similar messages [ 1816.737684] Lustre: 122720:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 1816.739393] Lustre: 122720:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1816.741259] Lustre: 122720:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 1816.743037] Lustre: 122720:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1816.744784] Lustre: 122720:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 4/150/2 [ 1816.747297] Lustre: 122720:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1816.749209] Lustre: 122720:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 1816.750263] LustreError: 125938:0:(lfsck_layout.c:4684:lfsck_layout_double_scan_one_trace_file()) cfs_fail_timeout id 1602 sleeping for 10000ms [ 1816.751062] Lustre: 122720:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1816.756039] Lustre: 122720:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1816.757890] Lustre: 122720:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 1819.368053] LustreError: 125931:0:(lfsck_layout.c:3380:lfsck_layout_scan_orphan()) cfs_fail_timeout interrupted [ 1824.062923] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 18:00:30 (1756677630) [ 1824.844035] Lustre: *** cfs_fail_loc=1616, val=0*** [ 1824.845530] Lustre: Skipped 3 previous similar messages [ 1828.536259] Lustre: *** cfs_fail_loc=161c, val=0*** [ 1835.071290] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 18:00:41 (1756677641) [ 1835.670688] Lustre: *** cfs_fail_loc=162e, val=0*** [ 1839.946679] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 18:00:46 (1756677646) [ 1840.954678] Lustre: *** cfs_fail_loc=162f, val=0*** [ 1840.955812] Lustre: Skipped 9 previous similar messages [ 1841.632773] LustreError: 128510:0:(lfsck_layout.c:2095:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x280000401:0xc6:0x0] and [0x280000401:0xc6:0x0]d: rc = 0 [ 1845.987048] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 18:00:52 (1756677652) [ 1850.556546] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 18:00:56 (1756677656) [ 1851.447123] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1851.448750] Lustre: 126048:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 275, rollback = 2 [ 1851.453484] Lustre: 126048:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 17 previous similar messages [ 1851.457509] Lustre: 126048:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1851.461526] Lustre: 126048:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 1851.465418] Lustre: 126048:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/275/0 [ 1851.468823] Lustre: 126048:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 1851.470922] Lustre: 126048:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 1851.473206] Lustre: 126048:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 1851.475168] Lustre: 126048:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1851.477064] Lustre: 126048:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 1851.479105] Lustre: 126048:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1851.480963] Lustre: 126048:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 17 previous similar messages [ 1851.492476] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1851.493615] Lustre: Skipped 3 previous similar messages [ 1853.857611] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.41@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:202 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 1854.881836] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.41@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 1857.301382] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 18:01:03 (1756677663) [ 1888.325091] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 18:01:34 (1756677694) [ 1889.452064] Lustre: *** cfs_fail_loc=1616, val=0*** [ 1889.454096] Lustre: Skipped 7 previous similar messages [ 1892.622211] LustreError: 130746:0:(lfsck_layout.c:2095:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x280000401:0xd3:0x0] and [0x280000401:0xd3:0x0]d: rc = 0 [ 1898.067630] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 18:01:44 (1756677704) [ 1901.645746] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 18:01:48 (1756677708) [ 1902.245816] Lustre: *** cfs_fail_loc=161e, val=0*** [ 1902.248649] Lustre: *** cfs_fail_loc=161e, val=0*** [ 1902.249790] Lustre: Skipped 1 previous similar message [ 1905.499254] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 18:01:51 (1756677711) [ 1905.978324] Lustre: *** cfs_fail_loc=161e, val=0*** [ 1905.980450] Lustre: *** cfs_fail_loc=161e, val=0*** [ 1909.303441] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 18:01:55 (1756677715) [ 1909.778666] Lustre: *** cfs_fail_loc=1620, val=0*** [ 1913.982113] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 1914.537921] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 18:02:00 (1756677720) [ 1916.298435] Lustre: *** cfs_fail_loc=1621, val=142*** [ 1916.299672] Lustre: Skipped 1 previous similar message [ 1917.220358] LustreError: 133457:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout id 1602 sleeping for 10000ms [ 1917.224929] LustreError: 133457:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 1 previous similar message [ 1917.263323] Lustre: 126590:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 1917.266150] Lustre: 126590:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 21 previous similar messages [ 1917.268555] Lustre: 126590:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1917.270292] Lustre: 126590:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 1917.272371] Lustre: 126590:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 1917.274735] Lustre: 126590:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 1917.278270] Lustre: 126590:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 1917.281823] Lustre: 126590:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 1917.285262] Lustre: 126590:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 1917.288136] Lustre: 126590:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 1917.290575] Lustre: 126590:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1917.293634] Lustre: 126590:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 1917.648080] LustreError: 133457:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) cfs_fail_timeout interrupted [ 1917.652960] LustreError: 133457:0:(lfsck_namespace.c:6360:lfsck_namespace_scan_local_lpf()) Skipped 1 previous similar message [ 1920.738653] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 18:02:07 (1756677727) [ 1921.400732] Lustre: Failing over lustre-MDT0000 [ 1921.725204] LustreError: 133943:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1921.726815] LustreError: 133943:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 1921.750565] Lustre: server umount lustre-MDT0000 complete [ 1922.529740] 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 [ 1922.529838] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1922.530414] LustreError: 124997:0:(ldlm_lib.c:1132: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. [ 1922.533318] Lustre: Skipped 3 previous similar messages [ 1924.761449] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1924.799880] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1924.872173] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1924.874346] Lustre: Skipped 3 previous similar messages [ 1924.896257] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1926.165702] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1926.369364] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1930.210418] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1930.220184] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 1930.232639] LustreError: 124370:0:(mdt_open.c:1315:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x91:0x0] doesn't exist!: rc = -14 [ 1930.239272] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:271 to 0x280000401:289) [ 1930.239277] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:138 to 0x2c0000401:161) [ 1933.607304] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 18:02:19 (1756677739) [ 1934.171374] Lustre: *** cfs_fail_loc=1622, val=0*** [ 1934.202287] Lustre: *** cfs_fail_loc=1622, val=0*** [ 1934.204423] Lustre: Skipped 1 previous similar message [ 1937.523112] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 18:02:23 (1756677743) [ 1937.966980] Lustre: *** cfs_fail_loc=1623, val=0*** [ 1941.360446] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 18:02:27 (1756677747) [ 1945.075150] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 18:02:31 (1756677751) [ 1945.519069] Lustre: *** cfs_fail_loc=1624, val=0*** [ 1945.521044] Lustre: Skipped 1 previous similar message [ 1948.661690] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 18:02:35 (1756677755) [ 1952.439927] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 18:02:38 (1756677758) [ 1956.247520] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 18:02:42 (1756677762) [ 1958.329669] Lustre: *** cfs_fail_loc=161c, val=0*** [ 1958.330655] Lustre: Skipped 1 previous similar message [ 1963.077357] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 18:02:49 (1756677769) [ 1963.613056] Lustre: *** cfs_fail_loc=1626, val=0*** [ 1963.614124] Lustre: Skipped 5 previous similar messages [ 1966.854389] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 18:02:53 (1756677773) [ 1976.293827] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 18:03:02 (1756677782) [ 1977.133938] LustreError: 122715:0:(osd_handler.c:268:osd_idc_find_or_init()) can't lookup: rc = -2 [ 1979.252487] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 18:03:05 (1756677785) [ 1981.643786] Lustre: Failing over lustre-MDT0000 [ 1981.763566] LustreError: 140368:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1981.766246] LustreError: 140368:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1981.806483] Lustre: server umount lustre-MDT0000 complete [ 1984.995611] LustreError: lustre-MDT0000-osp-MDT0001: operation out_update to node 0@lo failed: rc = -107 [ 1984.997825] 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 [ 1985.001712] LustreError: 122720:0:(ldlm_lib.c:1132: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. [ 1985.006709] LustreError: 122720:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 4 previous similar messages [ 1985.336887] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1985.370584] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1985.455195] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1986.736384] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1990.624709] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1990.626358] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1990.629773] Lustre: Skipped 3 previous similar messages [ 1990.630161] LustreError: 140948: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 [ 1990.637727] LustreError: 140948:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 1990.644721] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1990.661449] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:193) [ 1990.661461] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:321) [ 1994.705253] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 18:03:21 (1756677801) [ 1998.522709] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 18:03:24 (1756677804) [ 2002.148408] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 18:03:28 (1756677808) [ 2002.556845] Lustre: *** cfs_fail_loc=1629, val=0*** [ 2002.558294] Lustre: Skipped 9 previous similar messages [ 2033.094891] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 18:03:59 (1756677839) [ 2034.822863] Lustre: Failing over lustre-MDT0000 [ 2036.704551] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2036.705169] 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 [ 2036.705414] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2036.705419] Lustre: Skipped 3 previous similar messages [ 2036.715931] Lustre: Skipped 6 previous similar messages [ 2040.916145] Lustre: server umount lustre-MDT0000 complete [ 2041.824513] LustreError: 124194:0:(ldlm_lib.c:1132: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. [ 2041.831873] LustreError: 124194:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 3 previous similar messages [ 2044.000678] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2044.031417] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2044.096292] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2044.098147] Lustre: Skipped 1 previous similar message [ 2044.107875] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2045.323039] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2046.054741] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2046.057195] Lustre: lustre-MDT0000: Denying connection for new client eaf17809-0ec1-4a09-8ad1-3b6af0863906 (at 192.168.202.41@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 2049.508407] LustreError: 143620: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 [ 2049.513516] LustreError: 143620:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 2049.513866] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2049.521554] Lustre: Skipped 3 previous similar messages [ 2049.527517] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 2049.545055] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:225) [ 2049.545067] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:295 to 0x280000401:353) [ 2051.396562] Lustre: 125140:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 2051.399165] Lustre: 125140:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 114 previous similar messages [ 2051.401190] Lustre: 125140:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2051.403208] Lustre: 125140:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2051.405226] Lustre: 125140:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 2051.407199] Lustre: 125140:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2051.409075] Lustre: 125140:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 1/3/0 [ 2051.411193] Lustre: 125140:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2051.413100] Lustre: 125140:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2051.414926] Lustre: 125140:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2051.416831] Lustre: 125140:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2051.418734] Lustre: 125140:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 114 previous similar messages [ 2053.764365] Lustre: Failing over lustre-MDT0000 [ 2054.126240] LustreError: 144315:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2054.129530] LustreError: 144315:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 2054.159143] Lustre: server umount lustre-MDT0000 complete [ 2054.625023] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2054.625361] 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 [ 2054.633377] Lustre: Skipped 1 previous similar message [ 2057.177773] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2057.221718] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2057.344565] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2059.026437] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2061.538035] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2062.820467] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2062.823062] LustreError: 144795: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 [ 2062.824251] Lustre: Skipped 3 previous similar messages [ 2062.831444] LustreError: 144795:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 2062.847528] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2062.877476] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:355 to 0x280000401:385) [ 2062.877761] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:166 to 0x2c0000401:257) [ 2065.156250] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 18:04:31 (1756677871) [ 2069.224668] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 18:04:35 (1756677875) [ 2073.106574] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 18:04:39 (1756677879) [ 2106.374972] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 18:05:12 (1756677912) [ 2111.162816] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 18:05:17 (1756677917) [ 2113.316347] LustreError: 147228:0:(lfsck_layout.c:4469:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2114.257280] Lustre: Failing over lustre-OST0000 [ 2114.305847] Lustre: server umount lustre-OST0000 complete [ 2115.401090] LustreError: 147228:0:(lfsck_layout.c:4469:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 2115.410229] LustreError: lustre-OST0000-osc-MDT0000: operation lfsck_notify to node 0@lo failed: rc = -107 [ 2115.413747] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2115.418558] Lustre: Skipped 2 previous similar messages [ 2115.420522] LustreError: 125140:0:(ldlm_lib.c:1132: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. [ 2115.425801] LustreError: 125140:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 5 previous similar messages [ 2121.752255] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2121.802727] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2122.985703] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2122.991696] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2122.991697] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2122.991704] Lustre: Skipped 3 previous similar messages [ 2123.677114] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2126.620421] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 18:05:32 (1756677932) [ 2130.895943] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 2136.977796] Lustre: 150000:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2146.110274] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2155.317618] LustreError: 151243:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2155.321253] LustreError: 151243:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 2156.456252] Lustre: Failing over lustre-MDT0001 [ 2157.540183] 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 [ 2157.541312] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2157.551376] Lustre: Skipped 3 previous similar messages [ 2157.553626] Lustre: Skipped 4 previous similar messages [ 2158.336139] LustreError: 151240:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 2158.496154] Lustre: server umount lustre-MDT0001 complete [ 2159.489055] LustreError: 151240:0:(lfsck_striped_dir.c:1765:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 2166.086309] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2166.218358] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2167.664699] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2170.312109] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 18:06:16 (1756677976) [ 2171.362414] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2171.363227] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2171.368377] Lustre: Skipped 1 previous similar message [ 2171.373683] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2171.401094] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 2171.401652] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 2175.060213] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 2182.011160] Lustre: 153921:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2182.013792] Lustre: 153921:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 2191.451453] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2236.049307] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 18:07:22 (1756678042) [ 2236.571881] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 2237.199183] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 18:07:23 (1756678043) [ 2239.042815] Lustre: *** cfs_fail_loc=1631, val=0*** [ 2248.164113] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2248.164199] 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 [ 2248.164957] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2248.164967] Lustre: Skipped 1 previous similar message [ 2248.167293] LustreError: Skipped 1 previous similar message [ 2248.171148] Lustre: Skipped 3 previous similar messages [ 2250.637917] LustreError: 157167:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2250.641844] LustreError: 157167:0:(obd_class.h:479:obd_check_dev()) Skipped 19 previous similar messages [ 2250.688884] Lustre: server umount lustre-MDT0000 complete [ 2252.148380] LustreError: 125679:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756678058 with bad export cookie 7260563916237100147 [ 2252.150581] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2252.152823] LustreError: 125679:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 2252.305971] Lustre: server umount lustre-MDT0001 complete [ 2263.940154] Lustre: server umount lustre-OST0000 complete [ 2274.899458] Lustre: server umount lustre-OST0001 complete [ 2280.957930] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 2284.859656] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2285.072671] LustreError: 158945:0:(ldlm_lib.c:1132: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. [ 2285.078041] LustreError: 158945:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 6 previous similar messages [ 2285.097158] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2285.099096] Lustre: Skipped 3 previous similar messages [ 2286.666207] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2290.228760] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2291.753172] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2292.787879] Lustre: 160051:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2292.790268] Lustre: 160051:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 2295.102142] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2296.228734] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:542 to 0x280000401:577) [ 2297.339993] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2300.326422] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 2300.659140] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2302.326104] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 2302.330416] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:414 to 0x2c0000401:449) [ 2302.894847] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2305.884133] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2315.169511] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 18:08:41 (1756678121) [ 2315.633686] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 2316.137557] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 18:08:42 (1756678122) [ 2316.592777] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 2317.086701] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 18:08:43 (1756678123) [ 2317.540471] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 2318.042288] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 18:08:44 (1756678124) [ 2320.850764] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 18:08:47 (1756678127) [ 2320.912844] Lustre: 161666:0:(osd_internal.h:1341:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 445, rollback = 2 [ 2320.918912] Lustre: 161666:0:(osd_internal.h:1341:osd_trans_exec_op()) Skipped 364 previous similar messages [ 2320.923166] Lustre: 161666:0:(osd_handler.c:2079:osd_trans_dump_creds()) create: 4/16/2, destroy: 0/0/0 [ 2320.927282] Lustre: 161666:0:(osd_handler.c:2079:osd_trans_dump_creds()) Skipped 364 previous similar messages [ 2320.931623] Lustre: 161666:0:(osd_handler.c:2086:osd_trans_dump_creds()) attr_set: 4/4/0, xattr_set: 9/445/0 [ 2320.935893] Lustre: 161666:0:(osd_handler.c:2086:osd_trans_dump_creds()) Skipped 364 previous similar messages [ 2320.940092] Lustre: 161666:0:(osd_handler.c:2096:osd_trans_dump_creds()) write: 7/88/0, punch: 0/0/0, quota 1/3/0 [ 2320.944385] Lustre: 161666:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 364 previous similar messages [ 2320.948476] Lustre: 161666:0:(osd_handler.c:2103:osd_trans_dump_creds()) insert: 13/232/2, delete: 0/0/0 [ 2320.952235] Lustre: 161666:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 364 previous similar messages [ 2320.955827] Lustre: 161666:0:(osd_handler.c:2110:osd_trans_dump_creds()) ref_add: 5/5/0, ref_del: 0/0/0 [ 2320.959072] Lustre: 161666:0:(osd_handler.c:2110:osd_trans_dump_creds()) Skipped 364 previous similar messages [ 2325.657567] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 18:08:52 (1756678132) [ 2330.145924] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 18:08:56 (1756678136) [ 2334.770102] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 18:09:01 (1756678141) [ 2341.011993] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 18:09:07 (1756678147) [ 2372.529740] Lustre: *** cfs_fail_loc=1632, val=0*** [ 2377.388706] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 18:09:43 (1756678183) [ 2378.195754] Lustre: Failing over lustre-MDT0001 [ 2378.293106] Lustre: server umount lustre-MDT0001 complete [ 2381.776955] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2381.855469] 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 [ 2381.863494] Lustre: Skipped 1 previous similar message [ 2381.910967] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2381.911207] Lustre: lustre-MDT0001: Aborting client recovery [ 2381.915427] LustreError: 165674:0:(ldlm_lib.c:2935:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 2381.919899] Lustre: 165702:0:(ldlm_lib.c:2338:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2381.924205] Lustre: 165702:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client b8dadbb9-e8e3-411a-9ca5-d5261c25ca67@ [ 2381.929791] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 2381.933774] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 2381.939238] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 2381.965422] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 2381.965437] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:161) [ 2383.362858] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2384.765452] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 2386.366713] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 2386.916357] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2386.919858] Lustre: Skipped 2 previous similar messages [ 2386.923691] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 2387.550272] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 1 sec [ 2389.834323] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 18:09:56 (1756678196) [ 2391.862632] LustreError: 166691:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 sleeping for 3000ms [ 2391.867786] LustreError: 166691:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) Skipped 1 previous similar message [ 2393.439321] Lustre: Failing over lustre-MDT0000 [ 2394.888104] LustreError: 166691:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) cfs_fail_timeout id 1600 awake [ 2394.890081] LustreError: 166691:0:(lfsck_engine.c:836:lfsck_master_oit_engine()) Skipped 1 previous similar message [ 2394.996273] Lustre: server umount lustre-MDT0000 complete [ 2396.133692] LustreError: 158927:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756678202 with bad export cookie 7260563916237173255 [ 2396.136623] LustreError: 158927:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 2398.044271] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2398.073979] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2399.480587] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2402.017846] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2402.497115] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 18:10:08 (1756678208) [ 2403.301287] LustreError: 167368: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 [ 2403.304445] LustreError: 167368:0:(fld_handler.c:244:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0x280000401: rc = -2 [ 2403.307788] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2403.322834] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:490 to 0x2c0000401:513) [ 2403.322926] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 2413.257030] Lustre: Failing over lustre-OST0000 [ 2413.307392] Lustre: server umount lustre-OST0000 complete [ 2413.536646] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2413.538775] LustreError: 160406:0:(ldlm_lib.c:1132: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. [ 2413.543079] LustreError: 160406:0:(ldlm_lib.c:1132:target_handle_connect()) Skipped 12 previous similar messages [ 2415.278903] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2418.805606] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2418.863517] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2418.865145] Lustre: Skipped 3 previous similar messages [ 2420.650337] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2420.857155] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2420.859190] Lustre: Skipped 6 previous similar messages [ 2434.016899] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2434.018965] Lustre: Skipped 3 previous similar messages [ 2439.525193] Lustre: server umount lustre-MDT0000 complete [ 2443.067942] LustreError: 158926:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756678249 with bad export cookie 7260563916237183468 [ 2443.070925] LustreError: 158926:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2443.233041] Lustre: server umount lustre-MDT0001 complete [ 2457.288397] Lustre: server umount lustre-OST0000 complete [ 2471.524691] Lustre: server umount lustre-OST0001 complete [ 2478.052402] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 2479.241394] Key type lgssc unregistered [ 2479.385499] LNet: 173318:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2479.388525] LNetError: 173318:0:(acceptor.c:263:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2479.399549] LNet: Removed LNI 192.168.202.141@tcp [ 2479.741135] Key type .llcrypt unregistered [ 2479.742144] Key type ._llcrypt unregistered [ 2487.277953] Key type ._llcrypt registered [ 2487.279071] Key type .llcrypt registered [ 2487.318755] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 2493.780481] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 2494.144220] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 2494.153395] alg: No test for adler32 (adler32-zlib) [ 2495.010423] Lustre: Lustre: Build Version: 2.16.58_1_g28cf6eb [ 2495.097949] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 2496.680170] Key type lgssc registered [ 2497.086307] Lustre: Echo OBD driver; http://www.lustre.org/ [ 2501.355091] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2504.870873] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2507.269068] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2509.861430] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2514.437071] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 2518.898317] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2518.921194] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 2518.929827] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2520.020992] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2520.034288] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2520.079108] Lustre: lustre-MDT0000: new disk, initializing [ 2520.106514] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2520.113466] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2521.415979] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2526.653270] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2526.703979] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2526.743038] Lustre: 177697: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 [ 2526.757464] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2526.759452] Lustre: Skipped 1 previous similar message [ 2526.807070] Lustre: lustre-MDT0001: new disk, initializing [ 2526.829752] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2526.839722] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2526.843246] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2528.187209] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2530.470658] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2533.536041] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2533.565426] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2533.646469] Lustre: lustre-OST0000: new disk, initializing [ 2533.648081] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2533.665538] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2535.496044] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2537.715320] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2537.717818] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2537.742743] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2541.137625] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2541.173255] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2541.216010] Lustre: lustre-OST0001: new disk, initializing [ 2541.219357] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2541.249173] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2543.469947] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2547.701805] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2547.706467] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2547.731934] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2549.106580] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2551.736625] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2558.637458] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 18:12:44 (1756678364) === [ 2559.194235] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 2424 sec ========= 18:12:45 (1756678365) [ 2559.720990] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 18:12:46 (1756678366) === [ 2560.874204] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 18:12:47 (1756678367) === [ 2563.041051] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2563.041321] 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 [ 2563.041656] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2563.049079] Lustre: Skipped 2 previous similar messages [ 2567.994381] LustreError: 181875:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 2568.020909] Lustre: server umount lustre-MDT0000 complete [ 2570.779736] LustreError: 177689:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1756678377 with bad export cookie 9984182514844417036 [ 2570.781215] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2570.783643] LustreError: 177689:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2570.844603] LustreError: 182325:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 2570.846941] LustreError: 182325:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2570.924607] Lustre: server umount lustre-MDT0001 complete [ 2582.899527] LustreError: 182774:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 2582.901153] LustreError: 182774:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2582.918566] Lustre: server umount lustre-OST0000 complete [ 2594.799170] LustreError: 183225:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 2594.800842] LustreError: 183225:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2594.869560] Lustre: server umount lustre-OST0001 complete [ 2600.380792] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 2601.529422] Key type lgssc unregistered [ 2601.678392] LNet: 184057:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2601.681756] LNetError: 184057:0:(acceptor.c:263:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2601.691557] LNet: Removed LNI 192.168.202.141@tcp [ 2602.046168] Key type .llcrypt unregistered [ 2602.047128] Key type ._llcrypt unregistered