[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 625936588 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2576MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001012] APIC: Switch to symmetric I/O mode setup [ 0.002375] x2apic enabled [ 0.003010] Switched APIC routing to physical x2apic. [ 0.004016] kvm-guest: setup PV IPIs [ 0.007325] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008023] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009017] pid_max: default: 32768 minimum: 301 [ 0.010155] LSM: Security Framework initializing [ 0.011060] Yama: becoming mindful. [ 0.012036] SELinux: Initializing. [ 0.013063] *** VALIDATE selinux *** [ 0.022291] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026839] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028157] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029118] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030123] *** VALIDATE tmpfs *** [ 0.032009] *** VALIDATE proc *** [ 0.033286] *** VALIDATE cgroup *** [ 0.034053] *** VALIDATE cgroup2 *** [ 0.035324] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037104] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.038009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.039029] Spectre V2 : User space: Vulnerable [ 0.040009] Speculative Store Bypass: Vulnerable [ 0.042705] debug: unmapping init [mem 0xffffffffb1a59000-0xffffffffb1a60fff] [ 0.044192] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.045721] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.046028] ... version: 2 [ 0.047013] ... bit width: 48 [ 0.048013] ... generic registers: 4 [ 0.049024] ... value mask: 0000ffffffffffff [ 0.050014] ... max period: 00007fffffffffff [ 0.051015] ... fixed-purpose events: 3 [ 0.052013] ... event mask: 000000070000000f [ 0.053305] rcu: Hierarchical SRCU implementation. [ 0.055490] smp: Bringing up secondary CPUs ... [ 0.056673] x86: Booting SMP configuration: [ 0.057034] .... node #0, CPUs: #1 #2 #3 [ 0.061012] smp: Brought up 1 node, 4 CPUs [ 0.063018] smpboot: Max logical packages: 1 [ 0.064015] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.133702] node 0 deferred pages initialised in 67ms [ 0.136102] devtmpfs: initialized [ 0.137208] x86/mm: Memory block size: 128MB [ 0.139800] gcov: version magic: 0x41383552 [ 0.140656] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.144086] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.146253] pinctrl core: initialized pinctrl subsystem [ 0.147196] [ 0.147764] ************************************************************* [ 0.148011] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.149014] ** ** [ 0.150013] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.151016] ** ** [ 0.152014] ** This means that this kernel is built to expose internal ** [ 0.153019] ** IOMMU data structures, which may compromise security on ** [ 0.154013] ** your system. ** [ 0.155014] ** ** [ 0.156014] ** If you see this message and you are not debugging the ** [ 0.157015] ** kernel, report this immediately to your vendor! ** [ 0.158013] ** ** [ 0.159016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.160015] ************************************************************* [ 0.161683] NET: Registered protocol family 16 [ 0.162423] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.163066] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.164067] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.165434] cpuidle: using governor menu [ 0.167367] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.169399] PCI: Using configuration type 1 for base access [ 0.171182] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.177115] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.178033] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.180085] cryptd: max_cpu_qlen set to 1000 [ 0.182131] ACPI: Added _OSI(Module Device) [ 0.183012] ACPI: Added _OSI(Processor Device) [ 0.184011] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.185013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.189087] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.191718] ACPI: Interpreter enabled [ 0.192082] ACPI: PM: (supports S0 S3 S4 S5) [ 0.193014] ACPI: Using IOAPIC for interrupt routing [ 0.194131] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.195471] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.205231] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.206048] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.207024] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.208099] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.210333] acpiphp: Slot [2] registered [ 0.211120] acpiphp: Slot [5] registered [ 0.212119] acpiphp: Slot [6] registered [ 0.213141] acpiphp: Slot [7] registered [ 0.214102] acpiphp: Slot [8] registered [ 0.215212] acpiphp: Slot [9] registered [ 0.216119] acpiphp: Slot [10] registered [ 0.217124] acpiphp: Slot [3] registered [ 0.218110] acpiphp: Slot [4] registered [ 0.219094] acpiphp: Slot [11] registered [ 0.220054] acpiphp: Slot [12] registered [ 0.221084] acpiphp: Slot [13] registered [ 0.222089] acpiphp: Slot [14] registered [ 0.223062] acpiphp: Slot [15] registered [ 0.223876] acpiphp: Slot [16] registered [ 0.224049] acpiphp: Slot [17] registered [ 0.225094] acpiphp: Slot [18] registered [ 0.225891] acpiphp: Slot [19] registered [ 0.226051] acpiphp: Slot [20] registered [ 0.227096] acpiphp: Slot [21] registered [ 0.228116] acpiphp: Slot [22] registered [ 0.229105] acpiphp: Slot [23] registered [ 0.230153] acpiphp: Slot [24] registered [ 0.231102] acpiphp: Slot [25] registered [ 0.232108] acpiphp: Slot [26] registered [ 0.233147] acpiphp: Slot [27] registered [ 0.234086] acpiphp: Slot [28] registered [ 0.235068] acpiphp: Slot [29] registered [ 0.235965] acpiphp: Slot [30] registered [ 0.236086] acpiphp: Slot [31] registered [ 0.237056] PCI host bridge to bus 0000:00 [ 0.237864] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.240029] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.243023] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.244022] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.247029] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.250050] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.253211] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.254912] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.256911] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.264055] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.267048] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.270024] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.271014] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.273011] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.275359] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.276467] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.279041] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.281639] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.285014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.294015] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.298014] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.302164] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.309014] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.317034] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.353019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.370254] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.385031] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.400022] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.463026] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.493299] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.511019] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.533018] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.592033] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.619099] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.646027] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.667027] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.715029] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.741405] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.761023] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.777022] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.801057] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.816692] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.838020] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.855021] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.893022] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.908319] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.911416] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.914436] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.917401] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.919289] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.925374] iommu: Default domain type: Passthrough [ 0.927448] SCSI subsystem initialized [ 0.929152] ACPI: bus type USB registered [ 0.931099] usbcore: registered new interface driver usbfs [ 0.933091] usbcore: registered new interface driver hub [ 0.935154] usbcore: registered new device driver usb [ 0.937185] pps_core: LinuxPPS API ver. 1 registered [ 0.939013] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.942058] PTP clock support registered [ 0.944326] EDAC MC: Ver: 3.0.0 [ 0.946713] PCI: Using ACPI for IRQ routing [ 0.948923] NetLabel: Initializing [ 0.950012] NetLabel: domain hash size = 128 [ 0.952012] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.954117] NetLabel: unlabeled traffic allowed by default [ 0.957084] vgaarb: loaded [ 0.958389] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.960016] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.967381] clocksource: Switched to clocksource kvm-clock [ 1.070869] VFS: Disk quotas dquot_6.6.0 [ 1.072403] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.074935] *** VALIDATE ramfs *** [ 1.076021] *** VALIDATE hugetlbfs *** [ 1.077134] pnp: PnP ACPI init [ 1.079320] pnp: PnP ACPI: found 6 devices [ 1.101815] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.105396] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.107641] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.109901] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.112266] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.114534] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.117585] NET: Registered protocol family 2 [ 1.120148] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.124599] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.126966] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.131239] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.135079] TCP: Hash tables configured (established 65536 bind 65536) [ 1.137396] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.139597] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.141523] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.143888] NET: Registered protocol family 1 [ 1.147211] RPC: Registered named UNIX socket transport module. [ 1.148749] RPC: Registered udp transport module. [ 1.149863] RPC: Registered tcp transport module. [ 1.150948] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.152668] NET: Registered protocol family 44 [ 1.154139] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.156018] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.157729] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.159716] PCI: CLS 0 bytes, default 64 [ 1.161127] Unpacking initramfs... [ 2.605894] debug: unmapping init [mem 0xffff8a7abcc54000-0xffff8a7abffbffff] [ 2.609749] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.611969] software IO TLB: mapped [mem 0x00000000b8c54000-0x00000000bcc54000] (64MB) [ 2.614718] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.107800] Initialise system trusted keyrings [ 3.109761] Key type blacklist registered [ 3.111761] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.121422] zbud: loaded [ 3.125133] *** VALIDATE nfs *** [ 3.126457] *** VALIDATE nfs4 *** [ 3.128064] pstore: using deflate compression [ 3.131915] Platform Keyring initialized [ 3.237264] NET: Registered protocol family 38 [ 3.239124] Key type asymmetric registered [ 3.240741] Asymmetric key parser 'x509' registered [ 3.242359] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.245230] io scheduler mq-deadline registered [ 3.246855] io scheduler kyber registered [ 3.248581] io scheduler bfq registered [ 3.250709] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.253693] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.256597] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.259639] ACPI: Power Button [PWRF] [ 3.264692] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.270634] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.281700] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.290331] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.308595] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.337335] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.366023] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.371312] Non-volatile memory driver v1.3 [ 3.373217] Linux agpgart interface v0.103 [ 3.405442] virtio_blk virtio1: [vda] 147160 512-byte logical blocks (75.3 MB/71.9 MiB) [ 3.408114] vda: detected capacity change from 0 to 75345920 [ 3.425467] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.428775] vdb: detected capacity change from 0 to 1073741824 [ 3.444250] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.446805] vdc: detected capacity change from 0 to 2621440000 [ 3.469088] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.471905] vdd: detected capacity change from 0 to 2621440000 [ 3.490405] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.493613] vde: detected capacity change from 0 to 4294967296 [ 3.511149] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.513802] vdf: detected capacity change from 0 to 4294967296 [ 3.521359] libphy: Fixed MDIO Bus: probed [ 3.539591] usbcore: registered new interface driver usbserial_generic [ 3.542442] usbserial: USB Serial support registered for generic [ 3.544802] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.549105] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.551026] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.553591] mousedev: PS/2 mouse device common for all mice [ 3.556492] rtc_cmos 00:05: RTC can wake from S4 [ 3.556625] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.561277] rtc_cmos 00:05: registered as rtc0 [ 3.564188] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.567185] intel_pstate: CPU model not supported [ 3.569988] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.574637] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.574660] hid: raw HID events driver (C) Jiri Kosina [ 3.579935] usbcore: registered new interface driver usbhid [ 3.582078] usbhid: USB HID core driver [ 3.583674] drop_monitor: Initializing network drop monitor service [ 3.585898] Initializing XFRM netlink socket [ 3.587678] NET: Registered protocol family 10 [ 3.590808] Segment Routing with IPv6 [ 3.592316] NET: Registered protocol family 17 [ 3.594531] mpls_gso: MPLS GSO support [ 3.599081] RAS: Correctable Errors collector initialized. [ 3.601382] AVX version of gcm_enc/dec engaged. [ 3.602906] AES CTR mode by8 optimization enabled [ 3.672806] sched_clock: Marking stable (3672714233, 0)->(4665436831, -992722598) [ 3.676447] registered taskstats version 1 [ 3.679094] Loading compiled-in X.509 certificates [ 3.681419] zswap: loaded using pool lzo/zbud [ 3.704987] Key type big_key registered [ 3.716037] Key type encrypted registered [ 3.717501] ima: No TPM chip found, activating TPM-bypass! [ 3.719277] ima: Allocated hash algorithm: sha1 [ 3.720692] ima: No architecture policies found [ 3.722279] evm: Initialising EVM extended attributes: [ 3.723783] evm: security.selinux [ 3.724760] evm: security.ima [ 3.725676] evm: security.capability [ 3.726792] evm: HMAC attrs: 0x1 [ 3.728915] rtc_cmos 00:05: setting system clock to 2026-09-11 12:47:10 UTC (1789130830) [ 3.735087] debug: unmapping init [mem 0xffffffffb2a03000-0xffffffffb2bfffff] [ 3.737616] debug: unmapping init [mem 0xffffffffb1782000-0xffffffffb1a58fff] [ 3.747091] Write protecting the kernel read-only data: 28672k [ 3.750074] debug: unmapping init [mem 0xffffffffafe03000-0xffffffffafffffff] [ 3.752432] debug: unmapping init [mem 0xffffffffb0714000-0xffffffffb07fffff] [ 3.785366] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.792769] systemd[1]: Detected virtualization kvm. [ 3.794396] systemd[1]: Detected architecture x86-64. [ 3.795964] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.820941] systemd[1]: No hostname configured. [ 3.822631] systemd[1]: Set hostname to . [ 3.824480] random: systemd: uninitialized urandom read (16 bytes read) [ 3.826577] systemd[1]: Initializing machine ID from random generator. [ 3.853676] random: ln: uninitialized urandom read (6 bytes read) [ 3.949102] random: systemd: uninitialized urandom read (16 bytes read) [ 3.952321] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 3.957920] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 3.963437] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Timers. [ OK ] Reached target Slices. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Paths. [ OK ] Reached target Local File Systems. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Sockets. Starting Journal Service... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.485074] device-mapper: uevent: version 1.0.3 [ 4.487157] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.132250] virtio_net virtio0 ens2: renamed from eth0 [ 5.138513] random: fast init done [ 5.203685] scsi host0: ata_piix [ 5.257119] scsi host1: ata_piix [ 5.258662] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.261108] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.573911] dracut-initqueue[593]: RTNETLINK answers: File exists [ 10.231405] random: crng init done [ 10.232828] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 10.554363] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.826439] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.104479] SELinux: Disabled at runtime. [ 12.172594] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.181357] systemd[1]: Detected virtualization kvm. [ 12.183448] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.730658] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.734713] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.740460] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.746632] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.750684] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.762295] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.767659] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Stopped target Switch Root. [ OK ] Listening on udev Control Socket. [ OK ] Reached target rpc_pipefs.target. Starting Remount Root and Kernel File Systems... Starting Apply Kernel Variables... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Stopped target Initrd Root File System. [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting Huge Pages File System... Starting udev Coldplug all Devices... Mounting POSIX Message Queue File System... [ OK ] Created slice system-serial\x2dgetty.slice. Activating swap /dev/disk/by-label/SWAP... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Created slice system-getty.slice. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting Kernel Debug File System... [ OK ] Stopped target Initrd File Systems.[ 12.916695] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on Process Core Dump Socket. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Paths. [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.295836] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.671545] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.684990] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.860327] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.871955] EDAC sbridge: Ver: 1.1.2 [ 15.476225] Key type dns_resolver registered [ 15.807914] NFS: Registering the id_resolver key type [ 15.810459] Key type id_resolver registered [ 15.812310] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Basic System. [ OK ] Started D-Bus System Message Bus. Starting Login Service... [ OK ] Started irqbalance daemon. Starting Restore /run/initramfs on shutdown... Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. [ OK ] Started Authorization Manager. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg241-server login: [ 47.625186] hrtimer: interrupt took 2588113 ns [ 62.758723] libcfs: loading out-of-tree module taints kernel. [ 62.877791] Key type ._llcrypt registered [ 62.886227] Key type .llcrypt registered [ 63.111728] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 85.610354] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 88.409725] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 88.420687] alg: No test for adler32 (adler32-zlib) [ 90.339319] Lustre: Lustre: Build Version: 2.17.57_132_gd76390e [ 90.916409] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 92.848409] Key type lgssc registered [ 95.060810] Lustre: Echo OBD driver; http://www.lustre.org/ [ 115.987389] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 163.680988] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 184.272228] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 184.303513] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 185.695201] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 185.736925] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 185.858259] Lustre: lustre-MDT0000: new disk, initializing [ 186.004039] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 186.050756] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 190.365538] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 206.838260] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 207.090866] Lustre: 6517:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 207.155198] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 207.160822] Lustre: Skipped 1 previous similar message [ 207.303214] Lustre: lustre-MDT0001: new disk, initializing [ 207.461318] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 207.520423] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 207.553050] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 213.686189] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 218.822328] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 229.423173] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 229.774585] Lustre: lustre-OST0000: new disk, initializing [ 229.780903] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 229.795316] Lustre: 8455:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 229.881759] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 236.836264] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 238.169061] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 238.177801] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 238.317088] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 255.115526] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 255.259869] Lustre: lustre-OST0001: new disk, initializing [ 255.264652] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 255.272300] Lustre: 9528:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 255.355680] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 262.166640] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 262.180246] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 262.224287] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 263.029227] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 276.478881] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 285.809267] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 292.118746] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing check_logdir /tmp/testlogs/ [ 297.920762] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing yml_node [ 301.785732] Lustre: DEBUG MARKER: Client: 2.17.57.132 [ 304.524802] Lustre: DEBUG MARKER: MDS: 2.17.57.132 [ 308.558234] Lustre: DEBUG MARKER: OSS: 2.17.57.132 [ 311.710978] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Fri Sep 11 08:52:16 EDT 2026 [ 333.104673] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 343.832348] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 354.290422] 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 [ 354.297156] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 354.324198] Lustre: Skipped 2 previous similar messages [ 354.338025] Lustre: Skipped 3 previous similar messages [ 361.525441] Lustre: server umount lustre-MDT0000 complete [ 364.529359] LustreError: 6523:0:(ldlm_lib.c:1228: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. [ 364.588173] LustreError: 6523:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 8 previous similar messages [ 369.635776] LustreError: 7805:0:(ldlm_lib.c:1228: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.665592] LustreError: 7805:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 3 previous similar messages [ 372.429960] LustreError: 6508:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789131199 with bad export cookie 1804742002251687080 [ 372.436262] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 372.739328] Lustre: server umount lustre-MDT0001 complete [ 390.496722] Lustre: 3647:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789131201/real 1789131201] req@ffff8a7a041843c0 x1876039740534912/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789131217 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 390.519684] 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 [ 390.532893] Lustre: Skipped 1 previous similar message [ 393.505885] Lustre: 3646:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789131204/real 1789131204] req@ffff8a7a04284b40 x1876039740535168/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789131220 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 395.232176] Lustre: 3648:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789131206/real 1789131206] req@ffff8a7b350c0b40 x1876039740535424/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789131222 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 395.889698] Lustre: server umount lustre-OST0000 complete [ 398.690740] Lustre: 3646:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789131209/real 1789131209] req@ffff8a7a04184f00 x1876039740535808/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789131225 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 403.873224] Lustre: 3646:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789131214/real 1789131214] req@ffff8a7b3c002d00 x1876039740536320/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789131230 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 403.907752] Lustre: 3646:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 405.326793] Lustre: server umount lustre-OST0001 complete [ 422.202775] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 425.659680] Key type lgssc unregistered [ 426.022697] LNet: 14807:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 426.038261] LNetError: 14807:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 426.057948] LNet: Removed LNI 192.168.202.141@tcp [ 427.149198] Key type .llcrypt unregistered [ 427.153600] Key type ._llcrypt unregistered [ 453.290495] Key type ._llcrypt registered [ 453.293294] Key type .llcrypt registered [ 453.424412] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 469.855693] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 470.731996] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 470.754198] alg: No test for adler32 (adler32-zlib) [ 471.828541] Lustre: Lustre: Build Version: 2.17.57_132_gd76390e [ 472.144916] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 473.864822] Key type lgssc registered [ 475.403381] Lustre: Echo OBD driver; http://www.lustre.org/ [ 535.450289] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 550.270432] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 550.294284] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 551.595302] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 551.645976] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 551.770933] Lustre: lustre-MDT0000: new disk, initializing [ 551.880461] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 551.906588] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 557.476504] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 573.119563] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 573.267978] Lustre: 19267:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 573.320677] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 573.324066] Lustre: Skipped 1 previous similar message [ 573.379434] Lustre: lustre-MDT0001: new disk, initializing [ 573.520668] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 573.592854] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 573.607882] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 578.744626] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 583.812225] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 592.935636] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 593.201314] Lustre: lustre-OST0000: new disk, initializing [ 593.206418] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 593.219639] Lustre: 21205:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 593.289048] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 596.200925] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 596.222819] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 596.321094] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 600.080112] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 614.571422] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 614.711343] Lustre: lustre-OST0001: new disk, initializing [ 614.713974] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 614.718220] Lustre: 22230:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 614.811544] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 622.073384] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 623.658500] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 623.668203] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 623.745427] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 634.446668] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 642.123204] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 653.093958] Lustre: Setting parameter lustre.lod.lustre-MDT0000-mdtlov.enable_compr_rotational=1 in log params [ 660.609862] Lustre: Setting parameter lustre.lod.lustre-MDT0001-mdtlov.enable_compr_rotational=1 in log params [ 667.356273] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 08:58:12 (1789131492) === [ 671.562319] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 08:58:17 (1789131497) [ 671.863515] Lustre: 20759:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 671.872767] Lustre: 20759:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 671.881435] Lustre: 20759:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 671.886780] Lustre: 20759:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 671.892935] Lustre: 20759:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 671.904946] Lustre: 20759:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 672.402510] Lustre: 20759:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 672.409670] Lustre: 20759:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 11 previous similar messages [ 672.416356] Lustre: 20759:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 672.428203] Lustre: 20759:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 672.437386] Lustre: 20759:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 672.448273] Lustre: 20759:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 672.464642] Lustre: 20759:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 672.474189] Lustre: 20759:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 672.484394] Lustre: 20759:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 672.491884] Lustre: 20759:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 672.498041] Lustre: 20759:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 672.502289] Lustre: 20759:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 673.462737] Lustre: 19275:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 673.486084] Lustre: 19275:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 47 previous similar messages [ 673.496261] Lustre: 19275:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 673.507334] Lustre: 19275:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 673.526015] Lustre: 19275:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 673.535806] Lustre: 19275:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 673.555199] Lustre: 19275:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 673.576871] Lustre: 19275:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 673.587283] Lustre: 19275:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 673.602215] Lustre: 19275:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 673.614630] Lustre: 19275:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 673.619109] Lustre: 19275:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 47 previous similar messages [ 675.503194] Lustre: 19275:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 675.511411] Lustre: 19275:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 110 previous similar messages [ 675.518339] Lustre: 19275:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 675.524341] Lustre: 19275:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 110 previous similar messages [ 675.530490] Lustre: 19275:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 675.536967] Lustre: 19275:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 110 previous similar messages [ 675.600314] Lustre: 19275:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 675.609354] Lustre: 19275:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 113 previous similar messages [ 675.618417] Lustre: 19275:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 675.624460] Lustre: 19275:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 113 previous similar messages [ 675.630507] Lustre: 19275:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 675.638726] Lustre: 19275:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 113 previous similar messages [ 679.200290] Lustre: *** cfs_fail_loc=1600, val=3*** [ 682.331944] Lustre: 21194:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 260 < left 274, rollback = 2 [ 682.349964] Lustre: 21194:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 108 previous similar messages [ 682.372705] Lustre: 21194:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 682.386468] Lustre: 21194:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 108 previous similar messages [ 682.397047] Lustre: 21194:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 682.404379] Lustre: 21194:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 108 previous similar messages [ 682.414248] Lustre: 21194:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 682.423573] Lustre: 21194:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 105 previous similar messages [ 682.442441] Lustre: 21194:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 682.457718] Lustre: 21194:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 105 previous similar messages [ 682.473420] Lustre: 21194:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 682.477577] Lustre: 21194:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 105 previous similar messages [ 684.174088] Lustre: *** cfs_fail_loc=1600, val=3*** [ 697.653837] Lustre: 24114:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 697.659904] Lustre: 24113:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 697.670031] Lustre: 24114:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 63 previous similar messages [ 697.670060] Lustre: 24114:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 697.670064] Lustre: 24114:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 697.670069] Lustre: 24114:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 697.670072] Lustre: 24114:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 697.670077] Lustre: 24114:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 697.670080] Lustre: 24114:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 697.670085] Lustre: 24114:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 697.670089] Lustre: 24114:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 62 previous similar messages [ 697.738832] Lustre: 24113:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 700.387344] 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 [ 700.389319] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 700.410186] Lustre: Skipped 1 previous similar message [ 700.426267] Lustre: Skipped 1 previous similar message [ 705.523952] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 705.527311] Lustre: Skipped 3 previous similar messages [ 706.784376] Lustre: server umount lustre-MDT0000 complete [ 710.879165] LustreError: 19257:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789131537 with bad export cookie 14245132728403841001 [ 710.881600] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 710.889375] LustreError: 19257:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 711.451576] Lustre: server umount lustre-MDT0001 complete [ 725.574854] Lustre: server umount lustre-OST0000 complete [ 740.926471] Lustre: server umount lustre-OST0001 complete [ 750.311324] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 08:59:35 (1789131575) [ 764.888895] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 775.874410] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 776.378888] LustreError: 26985:0:(ldlm_lib.c:1228: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. [ 776.403029] LustreError: 26985:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 5 previous similar messages [ 776.515301] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 781.024540] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 781.793957] LustreError: 26986:0:(ldlm_lib.c:1228: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. [ 786.913163] LustreError: 26985:0:(ldlm_lib.c:1228: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. [ 789.408874] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 789.811896] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 795.129479] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 797.927561] Lustre: 28132:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 803.645567] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 810.331848] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 814.277544] LustreError: 28486:0:(ldlm_lib.c:1228: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. [ 819.680811] LustreError: 29008:0:(ldlm_lib.c:1228: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. [ 820.937882] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 821.196705] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 821.200899] Lustre: Skipped 1 previous similar message [ 822.256522] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 822.259483] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:40 to 0x280000401:65) [ 828.727728] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 837.653387] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 841.126939] Lustre: 30021:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 842.671693] Lustre: 28508:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 842.678345] Lustre: 28508:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 2 previous similar messages [ 842.688433] Lustre: 28508:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 842.694805] Lustre: 28508:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1 previous similar message [ 842.702760] Lustre: 28508:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 842.709865] Lustre: 28508:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 842.713297] Lustre: 28508:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 842.722928] Lustre: 28508:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 842.731699] Lustre: 28508:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 842.737309] Lustre: 28508:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 842.742189] Lustre: 28508:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 842.746860] Lustre: 28508:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 847.630524] Lustre: *** cfs_fail_loc=1501, val=0*** [ 856.566686] Lustre: Failing over lustre-MDT0000 [ 857.078343] Lustre: server umount lustre-MDT0000 complete [ 858.088835] 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 [ 858.122535] Lustre: Skipped 2 previous similar messages [ 858.130175] LustreError: 28508:0:(ldlm_lib.c:1228: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. [ 858.163593] LustreError: 28508:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 3 previous similar messages [ 870.582530] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 870.731910] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 871.107608] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 871.152283] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 876.539494] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 876.553992] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 876.601468] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 876.669333] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 876.689365] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 876.689460] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 880.512065] Lustre: *** cfs_fail_loc=1505, val=0*** [ 888.876790] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 09:01:54 (1789131714) [ 890.072754] Lustre: 26981:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 890.083307] Lustre: 26981:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 322 previous similar messages [ 890.088737] Lustre: 26981:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 890.094275] Lustre: 26981:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 890.100784] Lustre: 26981:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 890.106207] Lustre: 26981:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 890.112952] Lustre: 26981:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 890.119500] Lustre: 26981:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 890.124368] Lustre: 26981:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 890.129249] Lustre: 26981:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 890.135828] Lustre: 26981:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 890.141216] Lustre: 26981:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 895.556861] Lustre: *** cfs_fail_loc=1502, val=0*** [ 907.500115] Lustre: Failing over lustre-MDT0000 [ 907.951203] Lustre: server umount lustre-MDT0000 complete [ 912.381895] 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 [ 912.388049] LustreError: 26986:0:(ldlm_lib.c:1228: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. [ 912.390098] Lustre: Skipped 2 previous similar messages [ 912.414289] LustreError: 26986:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 11 previous similar messages [ 921.539386] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 921.719339] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 922.126583] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 927.210115] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 927.216203] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 927.232220] Lustre: Skipped 3 previous similar messages [ 927.263492] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 927.312240] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 927.313606] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 927.772328] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 931.950569] Lustre: *** cfs_fail_loc=1505, val=0*** [ 940.619328] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 09:02:45 (1789131765) [ 946.357977] Lustre: *** cfs_fail_loc=1504, val=0*** [ 946.360844] Lustre: *** cfs_fail_loc=1504, val=0*** [ 946.365419] Lustre: Skipped 1 previous similar message [ 955.720428] Lustre: Failing over lustre-MDT0000 [ 956.002290] Lustre: server umount lustre-MDT0000 complete [ 957.934586] 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 [ 957.944096] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 957.963584] Lustre: Skipped 4 previous similar messages [ 957.983488] LustreError: 26981:0:(ldlm_lib.c:1228: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. [ 958.007825] LustreError: 26981:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 7 previous similar messages [ 968.067340] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 968.231908] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 968.565231] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 968.575023] Lustre: Skipped 1 previous similar message [ 968.637600] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 973.521162] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 973.794579] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 973.799693] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 973.815380] Lustre: Skipped 3 previous similar messages [ 973.834853] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 973.886240] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 973.891106] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 977.109885] Lustre: *** cfs_fail_loc=1505, val=0*** [ 985.608532] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 09:03:31 (1789131811) [ 987.011088] Lustre: 26980:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 987.023587] Lustre: 26980:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 644 previous similar messages [ 987.027849] Lustre: 26980:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 987.044851] Lustre: 26980:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 987.059972] Lustre: 26980:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 987.070534] Lustre: 26980:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 987.086905] Lustre: 26980:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 987.092271] Lustre: 26980:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 987.101617] Lustre: 26980:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 987.109151] Lustre: 26980:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 987.114651] Lustre: 26980:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 987.120460] Lustre: 26980:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 992.809820] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1003.154580] Lustre: Failing over lustre-MDT0000 [ 1003.447822] Lustre: server umount lustre-MDT0000 complete [ 1004.512994] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1004.535679] 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 [ 1004.569160] Lustre: Skipped 1 previous similar message [ 1014.498205] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1014.799639] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1015.169819] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1020.173727] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1020.396646] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1020.400844] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1020.424695] Lustre: Skipped 3 previous similar messages [ 1020.459026] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1020.510247] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 1020.512099] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 1030.589976] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 09:04:15 (1789131855) [ 1035.564645] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1043.777292] Lustre: Failing over lustre-MDT0000 [ 1044.433427] Lustre: server umount lustre-MDT0000 complete [ 1045.985917] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1045.991755] 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 [ 1046.004927] LustreError: 26980:0:(ldlm_lib.c:1228: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. [ 1046.012384] Lustre: Skipped 6 previous similar messages [ 1046.042680] LustreError: 26980:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 23 previous similar messages [ 1056.423559] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1056.610417] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1057.079789] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1062.372847] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1062.386673] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1062.408253] Lustre: Skipped 3 previous similar messages [ 1062.434759] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1062.519562] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 1062.527617] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 1063.104667] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1072.529364] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 09:04:57 (1789131897) [ 1078.738617] Lustre: *** cfs_fail_loc=1605, val=0*** [ 1087.120355] Lustre: Failing over lustre-MDT0000 [ 1087.673463] Lustre: server umount lustre-MDT0000 complete [ 1087.979237] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1087.998593] 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 [ 1102.820669] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1102.972946] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1103.204677] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1103.221885] Lustre: Skipped 2 previous similar messages [ 1103.302261] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1108.459144] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1108.468268] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1108.490452] Lustre: Skipped 3 previous similar messages [ 1108.510798] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1108.572218] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 1108.583202] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 1109.460480] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1119.272064] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 09:05:44 (1789131944) [ 1120.627688] Lustre: 26982:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1120.643512] Lustre: 26982:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 968 previous similar messages [ 1120.651475] Lustre: 26982:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1120.658349] Lustre: 26982:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1120.668406] Lustre: 26982:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1120.676157] Lustre: 26982:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1120.683853] Lustre: 26982:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1120.694243] Lustre: 26982:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1120.704476] Lustre: 26982:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1120.714698] Lustre: 26982:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1120.719906] Lustre: 26982:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1120.728086] Lustre: 26982:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 968 previous similar messages [ 1125.319830] Lustre: *** cfs_fail_loc=161d, val=0*** [ 1134.224840] Lustre: Failing over lustre-MDT0000 [ 1134.812181] Lustre: server umount lustre-MDT0000 complete [ 1139.171781] 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 [ 1139.176035] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1139.186545] Lustre: Skipped 3 previous similar messages [ 1145.529686] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1145.617851] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1145.824023] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1150.134477] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1150.948683] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1150.955425] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1150.980390] Lustre: Skipped 3 previous similar messages [ 1151.030335] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1151.098307] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 1151.101544] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 1162.678594] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 09:06:27 (1789131987) [ 1166.759059] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1181.428725] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 09:06:46 (1789132006) [ 1188.028681] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1189.215671] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1201.333601] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 09:07:06 (1789132026) [ 1237.215132] Lustre: Failing over lustre-MDT0000 [ 1237.814820] Lustre: server umount lustre-MDT0000 complete [ 1237.985149] 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 [ 1237.987207] LustreError: 26980:0:(ldlm_lib.c:1228: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. [ 1237.994542] Lustre: Skipped 4 previous similar messages [ 1238.032694] LustreError: 26980:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 35 previous similar messages [ 1244.269905] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1255.121805] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1259.488340] Lustre: 16427:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789132069/real 1789132069] req@ffff8a7b3d331a40 x1876040140715008/t0(0) o400->MGC192.168.202.141@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789132085 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1259.523761] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1268.946319] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1268.984848] Lustre: lustre-MDT0000: reset Object Index mappings [ 1270.217614] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1275.369500] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1275.376274] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1275.391442] Lustre: Skipped 3 previous similar messages [ 1275.432449] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1275.508503] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1275.509547] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1276.556471] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1280.772246] LustreError: 43677:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1280.796403] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1282.848403] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1282.855027] Lustre: Skipped 1 previous similar message [ 1290.809683] Lustre: Failing over lustre-MDT0000 [ 1291.356176] Lustre: server umount lustre-MDT0000 complete [ 1295.841198] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1305.068605] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1310.785804] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1310.794191] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1311.515913] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1315.424397] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1324.391990] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 09:09:09 (1789132149) [ 1327.574790] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1339.464694] Lustre: Failing over lustre-MDT0000 [ 1339.723159] Lustre: server umount lustre-MDT0000 complete [ 1341.408893] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1346.331504] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1357.797271] Lustre: 16427:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789132168/real 1789132168] req@ffff8a7b3576c780 x1876040140816640/t0(0) o400->MGC192.168.202.141@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789132184 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1358.990298] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1372.805334] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1372.821784] Lustre: lustre-MDT0000: reset Object Index mappings [ 1382.720561] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1382.734763] Lustre: Skipped 3 previous similar messages [ 1382.793181] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1382.800864] Lustre: Skipped 1 previous similar message [ 1388.015536] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1388.033948] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1388.034678] Lustre: Skipped 1 previous similar message [ 1388.047557] Lustre: Skipped 7 previous similar messages [ 1388.057554] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1388.064186] Lustre: Skipped 1 previous similar message [ 1388.124775] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1388.125307] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1388.553233] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1392.542701] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1392.548663] Lustre: Skipped 2 previous similar messages [ 1405.735851] Lustre: Failing over lustre-MDT0000 [ 1406.256214] Lustre: server umount lustre-MDT0000 complete [ 1408.490769] 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 [ 1408.499396] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1408.522191] Lustre: Skipped 10 previous similar messages [ 1419.016266] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1419.218426] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1419.232929] LustreError: Skipped 2 previous similar messages [ 1424.786482] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1424.992550] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1424.993290] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1428.277603] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1428.279298] Lustre: Skipped 84 previous similar messages [ 1435.989767] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 09:11:01 (1789132261) [ 1437.171252] Lustre: 45265:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 278, rollback = 2 [ 1437.176571] Lustre: 45265:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 1271 previous similar messages [ 1437.182176] Lustre: 45265:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 1437.189323] Lustre: 45265:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1271 previous similar messages [ 1437.193840] Lustre: 45265:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1437.199025] Lustre: 45265:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1271 previous similar messages [ 1437.208026] Lustre: 45265:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1437.214852] Lustre: 45265:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1271 previous similar messages [ 1437.219837] Lustre: 45265:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 1437.223762] Lustre: 45265:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1271 previous similar messages [ 1437.227881] Lustre: 45265:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1437.231853] Lustre: 45265:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1271 previous similar messages [ 1443.480679] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1443.482860] Lustre: Skipped 7 previous similar messages [ 1464.497524] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 09:11:29 (1789132289) [ 1471.285561] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1471.296363] Lustre: Skipped 9 previous similar messages [ 1496.068703] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 09:12:01 (1789132321) [ 1504.778441] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1504.781066] Lustre: Skipped 12 previous similar messages [ 1510.757772] Lustre: Failing over lustre-MDT0000 [ 1511.014414] Lustre: server umount lustre-MDT0000 complete [ 1511.911591] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1511.916750] LustreError: 26982:0:(ldlm_lib.c:1228: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. [ 1511.939356] LustreError: 26982:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 91 previous similar messages [ 1521.453241] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1521.872300] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1521.893139] Lustre: Skipped 1 previous similar message [ 1527.285268] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1527.298376] Lustre: Skipped 1 previous similar message [ 1527.299757] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1527.321446] Lustre: Skipped 7 previous similar messages [ 1527.349384] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1527.356343] Lustre: Skipped 1 previous similar message [ 1527.401832] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:853 to 0x280000401:897) [ 1527.402038] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:854 to 0x2c0000401:897) [ 1527.490397] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1537.447654] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 09:12:43 (1789132363) [ 1554.822409] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1575.581812] Lustre: 53658:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1602.231625] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1606.799726] Lustre: 54795:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1613.170229] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1613.174846] Lustre: Skipped 81 previous similar messages [ 1615.687021] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1616.736134] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1617.760324] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1619.808173] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1619.812710] Lustre: Skipped 1 previous similar message [ 1619.932196] Lustre: Failing over lustre-MDT0000 [ 1622.263190] Lustre: server umount lustre-MDT0000 complete [ 1633.249855] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1639.510523] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:946 to 0x280000401:961) [ 1639.511405] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:947 to 0x2c0000401:993) [ 1641.663287] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1653.191144] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 09:14:38 (1789132478) [ 1659.872815] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1659.881643] LustreError: Skipped 1 previous similar message [ 1659.885901] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1664.995638] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1665.006991] Lustre: Skipped 6 previous similar messages [ 1670.114711] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1670.115290] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 4. Is it stuck? [ 1670.141557] Lustre: Skipped 3 previous similar messages [ 1670.482937] Lustre: server umount lustre-MDT0000 complete [ 1674.108200] LustreError: 30049:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789132500 with bad export cookie 14245132728404055831 [ 1674.114382] LustreError: 30049:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1674.283704] Lustre: server umount lustre-MDT0001 complete [ 1689.106724] Lustre: server umount lustre-OST0000 complete [ 1692.133350] Lustre: 16428:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789132502/real 1789132502] req@ffff8a7b04a39a40 x1876040141160320/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789132518 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1692.187147] 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 [ 1692.214770] Lustre: Skipped 15 previous similar messages [ 1695.592976] Lustre: server umount lustre-OST0001 complete [ 1704.428613] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 1714.790314] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1759.338723] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 1770.533824] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1771.165171] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1771.270594] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1771.434241] Lustre: lustre-MDT0000: new disk, initializing [ 1771.687679] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1775.936441] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1787.618898] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1787.759227] Lustre: 59861:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1787.852811] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1787.862370] Lustre: Skipped 1 previous similar message [ 1788.011429] Lustre: lustre-MDT0001: new disk, initializing [ 1788.190512] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1788.207876] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1793.782673] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1799.389658] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1809.347138] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1809.794548] Lustre: lustre-OST0000: new disk, initializing [ 1809.806634] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1809.814390] Lustre: 61491:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1810.879882] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1810.905469] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1810.956452] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1817.485578] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1828.803720] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1828.899535] Lustre: lustre-OST0001: new disk, initializing [ 1828.901461] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1828.907110] Lustre: 62362:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1830.497929] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1830.502810] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1830.535158] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1836.624721] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1848.021816] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1852.079650] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1863.061524] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1864.117296] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1864.121251] Lustre: Skipped 19 previous similar messages [ 1870.817830] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1870.832597] Lustre: Skipped 5 previous similar messages [ 1894.769409] Lustre: Failing over lustre-MDT0000 [ 1895.203890] Lustre: server umount lustre-MDT0000 complete [ 1907.371591] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1907.594933] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1907.614815] LustreError: Skipped 3 previous similar messages [ 1907.686645] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 1907.700635] Lustre: Skipped 3 previous similar messages [ 1907.955812] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1907.974013] Lustre: Skipped 7 previous similar messages [ 1908.033303] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1908.041363] Lustre: Skipped 1 previous similar message [ 1912.808879] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1913.330535] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1913.337077] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1913.337614] Lustre: Skipped 1 previous similar message [ 1913.363625] Lustre: Skipped 7 previous similar messages [ 1913.392305] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1913.404461] Lustre: Skipped 1 previous similar message [ 1913.450115] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1913.477476] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1913.480181] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1921.284814] Lustre: Failing over lustre-MDT0000 [ 1921.520557] Lustre: server umount lustre-MDT0000 complete [ 1923.560180] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1923.567684] LustreError: Skipped 1 previous similar message [ 1930.701222] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1936.939554] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1936.969158] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1936.973268] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1937.798157] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1945.150419] Lustre: Failing over lustre-MDT0000 [ 1945.782554] Lustre: server umount lustre-MDT0000 complete [ 1955.034716] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1960.620386] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1961.063735] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1961.063840] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1967.520124] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1980.821844] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 09:20:06 (1789132806) [ 1996.013683] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 2014.343545] Lustre: 69370:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2039.766615] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2043.545267] Lustre: 70505:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2052.007664] Lustre: 59866:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 2052.020289] Lustre: 59866:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 2759 previous similar messages [ 2052.031431] Lustre: 59866:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2052.049949] Lustre: 59866:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 2052.079066] Lustre: 59866:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2052.089730] Lustre: 59866:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 2052.103875] Lustre: 59866:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2052.124264] Lustre: 59866:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 2052.135936] Lustre: 59866:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2052.147906] Lustre: 59866:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 2052.161996] Lustre: 59866:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2052.170425] Lustre: 59866:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2759 previous similar messages [ 2161.819205] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 09:23:06 (1789132986) [ 2210.373420] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2210.375243] Lustre: Skipped 4 previous similar messages [ 2234.682561] Lustre: *** cfs_fail_loc=160c, val=0*** [ 2234.690693] Lustre: Skipped 10 previous similar messages [ 2274.755898] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 09:25:00 (1789133100) [ 2318.237776] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2319.242231] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2319.254329] Lustre: Skipped 38 previous similar messages [ 2321.252886] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2321.265020] Lustre: Skipped 101 previous similar messages [ 2325.266692] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2325.271855] Lustre: Skipped 264 previous similar messages [ 2333.270228] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2333.273377] Lustre: Skipped 411 previous similar messages [ 2349.277575] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2349.282732] Lustre: Skipped 876 previous similar messages [ 2381.277917] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2381.281433] Lustre: Skipped 1453 previous similar messages [ 2390.213469] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2390.217130] Lustre: Skipped 2599 previous similar messages [ 2644.097390] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 09:31:09 (1789133469) [ 2675.553363] Lustre: 63639:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 320, rollback = 2 [ 2675.562155] Lustre: 63639:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 36831 previous similar messages [ 2675.574290] Lustre: 63639:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 1/4/0 [ 2675.584721] Lustre: 63639:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2675.593126] Lustre: 63639:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 5/5/0, xattr_set: 7/320/0 [ 2675.604373] Lustre: 63639:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2675.614249] Lustre: 63639:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 6/46/0, punch: 0/0/0, quota 1/3/0 [ 2675.620392] Lustre: 63639:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2675.627568] Lustre: 63639:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 2/5/0 [ 2675.641866] Lustre: 63639:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2675.647398] Lustre: 63639:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/1 [ 2675.651910] Lustre: 63639:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 36831 previous similar messages [ 2785.248603] 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 [ 2785.250800] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2785.270116] Lustre: Skipped 14 previous similar messages [ 2785.286570] Lustre: Skipped 3 previous similar messages [ 2789.935351] Lustre: server umount lustre-MDT0000 complete [ 2790.370064] LustreError: 62928:0:(ldlm_lib.c:1228: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. [ 2790.382368] LustreError: 62928:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 40 previous similar messages [ 2793.637049] LustreError: 60654:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789133620 with bad export cookie 14245132728404074934 [ 2793.641161] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2793.644055] LustreError: 60654:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2793.660634] LustreError: Skipped 2 previous similar messages [ 2793.922538] Lustre: server umount lustre-MDT0001 complete [ 2808.927478] Lustre: server umount lustre-OST0000 complete [ 2811.872218] Lustre: 16426:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789133622/real 1789133622] req@ffff8a7b37ed6940 x1876040144951040/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789133638 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2813.416852] Lustre: server umount lustre-OST0001 complete [ 2821.294140] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2833.528412] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2849.312388] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2854.434178] LustreError: 75434:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.141@tcp: failed processing log, type 4: rc = -110 [ 2880.160247] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2880.166875] Lustre: Skipped 2 previous similar messages [ 2886.483336] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2890.428611] Lustre: 76018:0:(ofd_dev.c:565:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2890.439514] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2893.501753] Lustre: 76018:0:(ofd_dev.c:577:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2903.989619] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 09:35:28 (1789133728) [ 2925.701599] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 2941.286957] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2941.940934] LustreError: 75459:0:(ldlm_lib.c:1228: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. [ 2942.195214] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3271 to 0x280000401:3297) [ 2948.061071] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2957.827925] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2963.916715] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2967.058432] Lustre: 78635:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2981.961344] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2987.505468] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2988.381437] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2995.564453] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2998.519761] Lustre: 80133:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3002.560793] Lustre: *** cfs_fail_loc=160d, val=0*** [ 3003.134442] Lustre: *** cfs_fail_loc=160d, val=0*** [ 3003.136257] Lustre: Skipped 3 previous similar messages [ 3008.855416] Lustre: Failing over lustre-OST0000 [ 3008.929511] Lustre: server umount lustre-OST0000 complete [ 3009.508867] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 3009.518981] LustreError: Skipped 1 previous similar message [ 3020.060579] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3020.303815] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3020.322646] Lustre: Skipped 2 previous similar messages [ 3021.743799] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3021.764843] Lustre: Skipped 2 previous similar messages [ 3021.798825] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3021.801418] Lustre: *** cfs_fail_loc=215, val=0*** [ 3021.801550] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3021.801567] Lustre: Skipped 2 previous similar messages [ 3021.805512] Lustre: Skipped 11 previous similar messages [ 3021.848539] Lustre: Skipped 2 previous similar messages [ 3026.912993] Lustre: *** cfs_fail_loc=215, val=0*** [ 3026.920061] Lustre: Skipped 1 previous similar message [ 3028.680600] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3032.036294] Lustre: *** cfs_fail_loc=215, val=0*** [ 3032.510820] Lustre: 81531:0:(ofd_dev.c:565:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 3032.534372] Lustre: 81531:0:(ofd_dev.c:577:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 3035.935910] Lustre: Failing over lustre-OST0000 [ 3036.130134] Lustre: server umount lustre-OST0000 complete [ 3047.466578] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3049.223802] Lustre: *** cfs_fail_loc=215, val=0*** [ 3049.225612] Lustre: Skipped 1 previous similar message [ 3054.560684] Lustre: *** cfs_fail_loc=215, val=0*** [ 3054.562741] Lustre: Skipped 1 previous similar message [ 3055.244501] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3063.265849] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3068.385316] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3068.387621] Lustre: Skipped 5 previous similar messages [ 3073.512881] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3073.520480] Lustre: Skipped 3 previous similar messages [ 3076.064313] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 3076.340796] Lustre: server umount lustre-MDT0000 complete [ 3078.626258] LustreError: 77486:0:(ldlm_lib.c:1228: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. [ 3078.647338] LustreError: 77486:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 34 previous similar messages [ 3079.496909] LustreError: 75441:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789133906 with bad export cookie 14245132728405656136 [ 3079.526503] LustreError: 75441:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3080.133635] Lustre: server umount lustre-MDT0001 complete [ 3095.291351] Lustre: server umount lustre-OST0000 complete [ 3110.168351] Lustre: server umount lustre-OST0001 complete [ 3118.713467] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 09:39:04 (1789133944) [ 3131.684986] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 3140.415648] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3145.730907] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3154.905273] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3160.964282] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3164.076812] Lustre: 85918:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3170.937880] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3178.492471] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3186.667114] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 3187.148354] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3192.321687] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 3193.591720] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3201.254288] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3204.910218] Lustre: 87786:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3241.012150] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 09:41:06 (1789134066) [ 3256.264686] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 09:41:22 (1789134082) [ 3258.096718] Lustre: *** cfs_fail_loc=160f, val=0*** [ 3268.983685] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 09:41:34 (1789134094) [ 3271.980556] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3271.983403] Lustre: Skipped 3 previous similar messages [ 3277.058348] Lustre: 88313:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3277.066893] Lustre: 88313:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 1234 previous similar messages [ 3277.074513] Lustre: 88313:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3277.081527] Lustre: 88313:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 3277.093317] Lustre: 88313:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3277.101539] Lustre: 88313:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 3277.111022] Lustre: 88313:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/1, punch: 0/0/0, quota 1/3/2 [ 3277.117377] Lustre: 88313:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 3277.125706] Lustre: 88313:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 3277.131382] Lustre: 88313:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 3277.138358] Lustre: 88313:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3277.151345] Lustre: 88313:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1234 previous similar messages [ 3319.267068] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3323.134667] Lustre: server umount lustre-MDT0000 complete [ 3327.288088] LustreError: 84756:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789134154 with bad export cookie 14245132728405664592 [ 3327.323637] LustreError: 84756:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3328.149588] Lustre: server umount lustre-MDT0001 complete [ 3343.018339] Lustre: server umount lustre-OST0000 complete [ 3346.920486] Lustre: 16428:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789134157/real 1789134157] req@ffff8a7b0a2d6580 x1876040145280256/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789134173 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3348.313907] Lustre: server umount lustre-OST0001 complete [ 3364.108284] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 3374.736073] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3375.235807] LustreError: 92515:0:(ldlm_lib.c:1228: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. [ 3375.264808] LustreError: 92515:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 11 previous similar messages [ 3380.170067] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3390.520339] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3395.855668] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3399.300213] Lustre: 93656:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3406.438755] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3413.799291] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3416.049810] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 3421.178340] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 3422.060887] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3427.311332] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 3427.314065] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 3428.265956] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3435.545489] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3439.665421] Lustre: 95529:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3447.194769] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 09:44:32 (1789134272) [ 3452.672738] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3452.675376] Lustre: Skipped 63 previous similar messages [ 3478.497025] 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 [ 3478.511193] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3478.513982] Lustre: Skipped 16 previous similar messages [ 3478.542814] Lustre: Skipped 7 previous similar messages [ 3480.748866] Lustre: server umount lustre-MDT0000 complete [ 3485.996449] LustreError: 92495:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789134312 with bad export cookie 14245132728405693005 [ 3486.004580] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3486.005662] LustreError: 92495:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3486.019259] LustreError: Skipped 2 previous similar messages [ 3486.270553] Lustre: server umount lustre-MDT0001 complete [ 3500.882288] Lustre: server umount lustre-OST0000 complete [ 3504.802163] Lustre: 16427:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789134315/real 1789134315] req@ffff8a7a06ce1e00 x1876040145405696/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789134331 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3505.350143] Lustre: server umount lustre-OST0001 complete [ 3527.304588] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 3539.355335] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3540.065111] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3540.071898] Lustre: Skipped 13 previous similar messages [ 3545.388496] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3554.158368] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3559.105352] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3561.938156] Lustre: 99574:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3568.385725] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3575.260265] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3580.085516] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3583.953455] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3585.129396] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3585.138877] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3585.230544] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3589.791152] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3597.364472] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3609.766108] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 09:47:15 (1789134435) [ 3613.140536] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3613.142573] Lustre: Skipped 63 previous similar messages [ 3613.470908] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3626.772937] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 09:47:32 (1789134452) [ 3630.349676] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3630.446477] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3630.449450] Lustre: Skipped 2 previous similar messages [ 3643.839996] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 09:47:49 (1789134469) [ 3645.099669] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3646.455481] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 09:47:52 (1789134472) [ 3652.298204] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3652.301648] LustreError: 98440:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200003ab2:0x1:0x0]: rc = -5 [ 3652.306599] LustreError: 98440:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0001: migrate [0x240002340:0x6c:0x0]/s93 failed: rc = -5 [ 3728.354882] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3728.373039] LustreError: Skipped 3 previous similar messages [ 3728.381818] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3733.946554] Lustre: server umount lustre-MDT0000 complete [ 3742.227282] LustreError: 98415:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789134568 with bad export cookie 14245132728405707733 [ 3742.234384] LustreError: 98415:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3742.717732] Lustre: server umount lustre-MDT0001 complete [ 3759.460882] Lustre: 16426:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789134570/real 1789134570] req@ffff8a7b07f6b480 x1876040146047872/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789134586 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3759.526230] Lustre: server umount lustre-OST0000 complete [ 3764.219572] Lustre: 16428:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789134574/real 1789134574] req@ffff8a7a06fed2c0 x1876040146048128/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789134590 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3772.287543] Lustre: server umount lustre-OST0001 complete [ 3791.413770] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 3794.541603] Key type lgssc unregistered [ 3794.794250] LNet: 105286:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3794.798789] LNetError: 105286:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3794.812596] LNet: Removed LNI 192.168.202.141@tcp [ 3795.467215] Key type .llcrypt unregistered [ 3795.471393] Key type ._llcrypt unregistered [ 3825.544612] Key type ._llcrypt registered [ 3825.550187] Key type .llcrypt registered [ 3825.674622] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 3837.997338] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 3838.461521] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3838.520400] alg: No test for adler32 (adler32-zlib) [ 3839.517954] Lustre: Lustre: Build Version: 2.17.57_132_gd76390e [ 3839.742735] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 3841.410614] Key type lgssc registered [ 3843.147734] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3893.122616] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 3905.464113] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3905.521656] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3906.872485] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3906.930791] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3907.037378] Lustre: lustre-MDT0000: new disk, initializing [ 3907.164596] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3907.208422] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3912.419550] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3928.933798] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3929.030349] Lustre: 109722:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3929.054528] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3929.059033] Lustre: Skipped 1 previous similar message [ 3929.121984] Lustre: lustre-MDT0001: new disk, initializing [ 3929.291226] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3929.362859] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3929.382968] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3934.411526] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3939.908828] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3952.958930] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3953.453467] Lustre: lustre-OST0000: new disk, initializing [ 3953.457508] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3953.464168] Lustre: 111663:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3953.610250] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3960.859606] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3960.932247] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3960.959282] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3961.113170] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3978.212186] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3978.355987] Lustre: lustre-OST0001: new disk, initializing [ 3978.359111] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3978.361695] Lustre: 112688:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3978.466196] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3987.018388] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3987.034568] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3987.142703] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3987.785951] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4000.904767] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4008.617634] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4018.089611] Lustre: Setting parameter lustre.lod.lustre-MDT0000-mdtlov.enable_compr_rotational=1 in log params [ 4025.171546] Lustre: Setting parameter lustre.lod.lustre-MDT0001-mdtlov.enable_compr_rotational=1 in log params [ 4031.780750] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 09:54:17 (1789134857) === [ 4038.955741] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 09:54:24 (1789134864) [ 4039.118838] Lustre: 114229:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 4039.128420] Lustre: 114229:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4039.136742] Lustre: 114229:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4039.147332] Lustre: 114229:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 4039.153173] Lustre: 114229:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 4039.156741] Lustre: 114229:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4039.660802] Lustre: 114229:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4039.670477] Lustre: 114229:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 6 previous similar messages [ 4039.677560] Lustre: 114229:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4039.682864] Lustre: 114229:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 4039.687556] Lustre: 114229:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4039.691500] Lustre: 114229:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 4039.694945] Lustre: 114229:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4039.698229] Lustre: 114229:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 4039.702665] Lustre: 114229:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4039.706447] Lustre: 114229:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 4039.709867] Lustre: 114229:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4039.712877] Lustre: 114229:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 6 previous similar messages [ 4040.670102] Lustre: 109730:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 4040.675302] Lustre: 109730:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 203 previous similar messages [ 4040.679470] Lustre: 109730:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4040.683736] Lustre: 109730:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 4040.688420] Lustre: 109730:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4040.692390] Lustre: 109730:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 4040.696953] Lustre: 109730:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 4040.701172] Lustre: 109730:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 4040.705657] Lustre: 109730:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 4040.711264] Lustre: 109730:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 4040.715220] Lustre: 109730:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4040.724445] Lustre: 109730:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 203 previous similar messages [ 4042.180860] Lustre: *** cfs_fail_loc=1613, val=0*** [ 4056.495278] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 09:54:41 (1789134881) [ 4058.146340] Lustre: 109731:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 278, rollback = 2 [ 4058.156286] Lustre: 109731:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 98 previous similar messages [ 4058.163934] Lustre: 109731:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 4058.171986] Lustre: 109731:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 98 previous similar messages [ 4058.178129] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4058.184902] Lustre: 109731:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 98 previous similar messages [ 4058.189368] Lustre: 109731:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4058.193870] Lustre: 109731:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 98 previous similar messages [ 4058.200302] Lustre: 109731:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 4058.205977] Lustre: 109731:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 98 previous similar messages [ 4058.211216] Lustre: 109731:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4058.218834] Lustre: 109731:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 98 previous similar messages [ 4059.794687] Lustre: *** cfs_fail_loc=1614, val=0*** [ 4064.409330] Lustre: 111654:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 4064.415652] Lustre: 111654:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 11 previous similar messages [ 4064.422384] Lustre: 111654:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 4064.432629] Lustre: 111654:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4064.436326] Lustre: 111654:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 4064.439090] Lustre: 111654:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4064.451107] Lustre: 111654:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 4064.465993] Lustre: 111654:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4064.471431] Lustre: 111654:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 4064.476136] Lustre: 111654:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4064.480113] Lustre: 111654:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4064.485769] Lustre: 111654:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4072.112287] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 09:54:57 (1789134897) [ 4072.491907] Lustre: 109729:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 253 < left 278, rollback = 2 [ 4072.501577] Lustre: 109729:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 1 previous similar message [ 4072.509332] Lustre: 109729:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4072.514134] Lustre: 109729:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4072.527376] Lustre: 109729:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4072.537317] Lustre: 109729:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4072.543271] Lustre: 109729:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 4072.552211] Lustre: 109729:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4072.559959] Lustre: 109729:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 4072.564402] Lustre: 109729:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4072.569295] Lustre: 109729:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4072.577244] Lustre: 109729:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4075.314788] Lustre: *** cfs_fail_loc=1615, val=0*** [ 4075.320975] Lustre: Skipped 1 previous similar message [ 4076.954884] Lustre: *** cfs_fail_loc=1615, val=0*** [ 4076.961055] Lustre: Skipped 1 previous similar message [ 4096.935685] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 4099.108768] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 09:55:24 (1789134924) [ 4099.541622] Lustre: 109729:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4099.548831] Lustre: 109729:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 21 previous similar messages [ 4099.555746] Lustre: 109729:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4099.560117] Lustre: 109729:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4099.564406] Lustre: 109729:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4099.568926] Lustre: 109729:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4099.573025] Lustre: 109729:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4099.577212] Lustre: 109729:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4099.582305] Lustre: 109729:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4099.585766] Lustre: 109729:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4099.588495] Lustre: 109729:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4099.590962] Lustre: 109729:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4101.799989] Lustre: *** cfs_fail_loc=1617, val=0*** [ 4101.952322] Lustre: *** cfs_fail_loc=1617, val=0*** [ 4104.702868] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4104.721574] Lustre: Skipped 3 previous similar messages [ 4128.974678] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 09:55:53 (1789134953) [ 4131.862354] Lustre: *** cfs_fail_loc=1618, val=0*** [ 4131.865735] Lustre: Skipped 5 previous similar messages [ 4131.868791] Lustre: 109729:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 276, rollback = 2 [ 4131.876198] Lustre: 109729:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 44 previous similar messages [ 4131.885503] Lustre: 109729:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4131.895390] Lustre: 109729:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 4131.904813] Lustre: 109729:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 6/276/0 [ 4131.918125] Lustre: 109729:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 4131.926321] Lustre: 109729:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 6/46/0, punch: 0/0/0, quota 9/459/0 [ 4131.941637] Lustre: 109729:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 4131.950368] Lustre: 109729:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/0, delete: 0/0/0 [ 4131.963939] Lustre: 109729:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 4131.976550] Lustre: 109729:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4131.983534] Lustre: 109729:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 44 previous similar messages [ 4169.708965] 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 [ 4169.716253] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4169.732623] Lustre: Skipped 2 previous similar messages [ 4169.755877] Lustre: Skipped 3 previous similar messages [ 4171.763501] Lustre: server umount lustre-MDT0000 complete [ 4176.126626] LustreError: 109714:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789135002 with bad export cookie 136827368169953475 [ 4176.130252] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4176.131579] LustreError: 109714:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4176.607427] Lustre: server umount lustre-MDT0001 complete [ 4191.072621] Lustre: server umount lustre-OST0000 complete [ 4206.084359] Lustre: server umount lustre-OST0001 complete [ 4223.586896] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 4236.040234] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4236.408605] LustreError: 119053:0:(ldlm_lib.c:1228: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. [ 4236.430195] LustreError: 119053:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 5 previous similar messages [ 4236.490140] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4241.513605] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4241.889164] LustreError: 119054:0:(ldlm_lib.c:1228: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. [ 4247.017330] LustreError: 119053:0:(ldlm_lib.c:1228: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. [ 4251.540573] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4251.905045] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4256.427235] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4259.421906] Lustre: 120198:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4267.030854] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4274.338684] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4276.590872] LustreError: 120553:0:(ldlm_lib.c:1228: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. [ 4276.609421] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 4281.729373] LustreError: 120554:0:(ldlm_lib.c:1228: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. [ 4281.749271] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 4281.754613] LustreError: 120554:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 1 previous similar message [ 4284.429790] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4284.704936] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 4284.713468] Lustre: Skipped 1 previous similar message [ 4290.040261] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 4290.044371] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 4292.074519] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4299.119806] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4304.075974] Lustre: 122072:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4324.603713] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 09:59:10 (1789135150) [ 4325.123761] Lustre: 120574:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 4325.132987] Lustre: 120574:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 1 previous similar message [ 4325.136758] Lustre: 120574:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4325.142835] Lustre: 120574:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4325.152723] Lustre: 120574:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4325.162848] Lustre: 120574:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4325.171917] Lustre: 120574:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 4325.180215] Lustre: 120574:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4325.187783] Lustre: 120574:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 4325.196362] Lustre: 120574:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4325.206855] Lustre: 120574:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4325.214745] Lustre: 120574:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1 previous similar message [ 4327.074430] Lustre: *** cfs_fail_loc=1618, val=0*** [ 4327.077488] Lustre: Skipped 3 previous similar messages [ 4361.698462] 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 [ 4361.701543] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4361.726960] Lustre: Skipped 3 previous similar messages [ 4361.761889] Lustre: Skipped 3 previous similar messages [ 4363.912576] Lustre: server umount lustre-MDT0000 complete [ 4366.818750] LustreError: 119054:0:(ldlm_lib.c:1228: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. [ 4366.847518] LustreError: 119054:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 3 previous similar messages [ 4369.735144] LustreError: 119082:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789135196 with bad export cookie 136827368169968882 [ 4369.752196] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4369.756830] LustreError: 119082:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4370.403554] Lustre: server umount lustre-MDT0001 complete [ 4385.087993] Lustre: server umount lustre-OST0000 complete [ 4387.296428] Lustre: 106882:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789135198/real 1789135198] req@ffff8a7a04a48b40 x1876043671851136/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789135214 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4387.313261] 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 [ 4387.320312] Lustre: Skipped 1 previous similar message [ 4389.435375] Lustre: server umount lustre-OST0001 complete [ 4409.670696] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 4423.104141] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4423.750814] LustreError: 124641:0:(ldlm_lib.c:1228: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. [ 4423.874700] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4429.547921] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4438.760041] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4443.376707] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4447.161613] Lustre: 125796:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4455.709606] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4464.164467] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4464.679431] LustreError: 126151:0:(ldlm_lib.c:1228: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. [ 4464.702302] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 4464.704679] LustreError: 126151:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 3 previous similar messages [ 4470.772509] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 4474.277177] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4479.996754] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 4479.998413] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 4480.799304] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4490.289711] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4494.946807] Lustre: 127670:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4501.968631] Lustre: 125673:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 4501.978111] Lustre: 125673:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 21 previous similar messages [ 4501.994198] Lustre: 125673:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4501.998875] Lustre: 125673:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4502.010169] Lustre: 125673:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 4502.023161] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4502.030582] Lustre: 125673:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4502.038752] Lustre: 125673:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 4502.043501] Lustre: 125673:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4502.047333] Lustre: 125673:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 4502.051257] Lustre: 125673:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4502.057416] Lustre: 125673:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4502.068566] Lustre: 125673:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4527.842891] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 10:02:33 (1789135353) [ 4530.311042] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4530.316907] Lustre: Skipped 3 previous similar messages [ 4537.007488] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4562.210856] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 10:03:08 (1789135388) [ 4563.788187] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4563.790725] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4563.792846] Lustre: Skipped 7 previous similar messages [ 4577.852217] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 10:03:23 (1789135403) [ 4597.981344] Lustre: DEBUG MARKER: == sanity-lfsck test 18i: LFSCK can repair crashed PFL with compression ========================================================== 10:03:43 (1789135423) [ 4616.717284] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 10:04:02 (1789135442) [ 4630.029634] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 10:04:15 (1789135455) [ 4633.299238] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4633.340479] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4633.346687] Lustre: Skipped 3 previous similar messages [ 4638.553777] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.41@tcp inode [0x2000013a1:0x25:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 4639.640416] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.41@tcp inode [0x2000013a1:0x26:0x0] object 0x280000401:205 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 4647.970530] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 10:04:33 (1789135473) [ 4649.864334] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4649.868274] Lustre: Skipped 5 previous similar messages [ 4700.314649] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 10:05:25 (1789135525) [ 4709.307349] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 10:05:32 (1789135532) [ 4727.363819] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 10:05:51 (1789135551) [ 4730.700402] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4730.735975] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4730.737621] Lustre: Skipped 1 previous similar message [ 4745.514631] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 10:06:10 (1789135570) [ 4747.281250] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4747.283462] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4756.934900] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 10:06:22 (1789135582) [ 4758.187746] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4763.383347] Lustre: 124642:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0001: opcode 2: before 251 < left 263, rollback = 2 [ 4763.396916] Lustre: 124642:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 483 previous similar messages [ 4763.415326] Lustre: 124642:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4763.425602] Lustre: 124642:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 483 previous similar messages [ 4763.432758] Lustre: 124642:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/263/0 [ 4763.437470] Lustre: 124642:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 483 previous similar messages [ 4763.442392] Lustre: 124642:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 5/50/0, punch: 0/0/0, quota 1/3/2 [ 4763.447962] Lustre: 124642:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 483 previous similar messages [ 4763.453470] Lustre: 124642:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 3/69/3, delete: 0/0/0 [ 4763.458455] Lustre: 124642:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 483 previous similar messages [ 4763.463325] Lustre: 124642:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 4763.468087] Lustre: 124642:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 483 previous similar messages [ 4774.525935] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4776.860832] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 10:06:42 (1789135602) [ 4784.846823] Lustre: *** cfs_fail_loc=1621, val=127*** [ 4784.848566] Lustre: Skipped 1 previous similar message [ 4788.373565] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4811.708233] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 10:07:17 (1789135637) [ 4814.337115] Lustre: Failing over lustre-MDT0000 [ 4814.893910] Lustre: server umount lustre-MDT0000 complete [ 4817.789030] LustreError: 124637:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.41@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4817.809592] LustreError: 124637:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 3 previous similar messages [ 4817.889770] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4817.897045] 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 [ 4817.897892] LustreError: 124623:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789135644 with bad export cookie 136827368169972900 [ 4817.908342] Lustre: Skipped 2 previous similar messages [ 4817.938249] LustreError: 124623:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 4827.164827] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4827.448952] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4828.077627] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4828.093978] Lustre: Skipped 3 previous similar messages [ 4828.181518] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4829.360145] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4833.255207] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4833.295822] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 4833.348185] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:131 to 0x2c0000401:161) [ 4833.349868] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:267 to 0x280000401:289) [ 4833.928670] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4837.775253] LustreError: 127683:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4853.313330] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 10:07:58 (1789135678) [ 4855.947906] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4856.172791] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4856.175608] Lustre: Skipped 1 previous similar message [ 4868.582674] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 10:08:13 (1789135693) [ 4870.544341] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4880.769533] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 10:08:26 (1789135706) [ 4882.687540] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4896.384468] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 10:08:40 (1789135720) [ 4913.049527] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 10:08:58 (1789135738) [ 4915.097133] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4915.099130] Lustre: Skipped 1 previous similar message [ 4931.309113] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 10:09:15 (1789135755) [ 4945.169881] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 10:09:30 (1789135770) [ 4947.837170] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4947.844151] Lustre: Skipped 2 previous similar messages [ 4952.623971] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4952.629799] Lustre: Skipped 1 previous similar message [ 4971.326145] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 10:09:56 (1789135796) [ 4985.133495] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 10:10:10 (1789135810) [ 5013.814476] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 10:10:39 (1789135839) [ 5015.612582] Lustre: *** cfs_fail_loc=1626, val=0*** [ 5015.624252] Lustre: Skipped 2 previous similar messages [ 5016.743504] LustreError: 124637:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 5024.254305] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 10:10:49 (1789135849) [ 5047.484843] Lustre: Failing over lustre-MDT0000 [ 5047.820958] Lustre: server umount lustre-MDT0000 complete [ 5048.289734] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5048.296477] 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 [ 5048.303016] LustreError: 124642:0:(ldlm_lib.c:1228: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. [ 5048.303026] LustreError: 124642:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 9 previous similar messages [ 5048.371162] Lustre: Skipped 4 previous similar messages [ 5059.514210] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5059.713532] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5060.087277] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5060.164651] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5065.206922] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5065.212975] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5065.254190] Lustre: Skipped 3 previous similar messages [ 5065.282916] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5065.356662] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 5065.357119] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 5065.580959] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5078.749920] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 10:11:44 (1789135904) [ 5093.743643] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 10:11:59 (1789135919) [ 5109.607971] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 10:12:14 (1789135934) [ 5110.996431] Lustre: *** cfs_fail_loc=1629, val=0*** [ 5111.005205] Lustre: Skipped 5 previous similar messages [ 5140.730218] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 10:12:46 (1789135966) [ 5147.659375] Lustre: Failing over lustre-MDT0000 [ 5148.217539] Lustre: server umount lustre-MDT0000 complete [ 5152.225410] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5152.228550] 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 [ 5155.833786] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5155.985572] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5156.354554] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5160.838823] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5161.449240] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5161.455501] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 5161.467382] Lustre: Skipped 3 previous similar messages [ 5161.485853] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5161.536113] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 5161.538226] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 5172.686658] Lustre: Failing over lustre-MDT0000 [ 5173.259563] Lustre: server umount lustre-MDT0000 complete [ 5176.800842] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5176.804692] 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 [ 5176.822812] Lustre: Skipped 4 previous similar messages [ 5182.535601] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5182.685583] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5182.987692] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5183.325901] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5188.090559] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 5188.099079] Lustre: Skipped 3 previous similar messages [ 5188.123183] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 5188.203812] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:257) [ 5188.207828] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:355 to 0x280000401:385) [ 5188.345067] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5199.081847] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 10:13:44 (1789136024) [ 5212.760659] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 10:13:58 (1789136038) [ 5227.656262] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 10:14:12 (1789136052) [ 5266.911566] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 10:14:52 (1789136092) [ 5278.584662] Lustre: 124637:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0001: opcode 2: before 252 < left 278, rollback = 2 [ 5278.601382] Lustre: 124637:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 565 previous similar messages [ 5278.624064] Lustre: 124637:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 5278.636779] Lustre: 124637:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 565 previous similar messages [ 5278.649173] Lustre: 124637:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 5278.662734] Lustre: 124637:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 565 previous similar messages [ 5278.679591] Lustre: 124637:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/1, punch: 0/0/0, quota 1/3/2 [ 5278.692406] Lustre: 124637:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 565 previous similar messages [ 5278.700305] Lustre: 124637:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 5278.722752] Lustre: 124637:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 565 previous similar messages [ 5278.739157] Lustre: 124637:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 5278.747597] Lustre: 124637:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 565 previous similar messages [ 5290.440299] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 10:15:15 (1789136115) [ 5300.582210] LustreError: 149674:0:(lfsck_layout.c:4564:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5303.490160] Lustre: Failing over lustre-OST0000 [ 5303.668641] LustreError: 149674:0:(lfsck_layout.c:4564:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 5303.679553] LustreError: 149674:0:(lfsck_layout.c:4564:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5303.831092] Lustre: server umount lustre-OST0000 complete [ 5304.320169] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 5304.333188] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5304.342126] Lustre: Skipped 1 previous similar message [ 5304.351824] LustreError: 126151:0:(ldlm_lib.c:1228: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. [ 5304.371716] LustreError: 126151:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 25 previous similar messages [ 5306.719934] LustreError: 149674:0:(lfsck_layout.c:4564:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 5306.731375] LustreError: 149674:0:(lfsck_layout.c:4564:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5306.960887] LustreError: 149674:0:(lfsck_layout.c:4564:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 5319.021106] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5319.208064] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5319.211525] Lustre: Skipped 2 previous similar messages [ 5319.221931] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 5320.484367] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5320.516634] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 5320.521272] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 5320.528949] Lustre: Skipped 3 previous similar messages [ 5325.936924] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5334.500488] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 10:15:59 (1789136159) [ 5348.896623] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 5368.740660] Lustre: 152483:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5394.108902] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5398.436685] Lustre: 153619:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5409.672391] LustreError: 153737:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5409.702174] LustreError: 153737:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 5412.561380] Lustre: Failing over lustre-MDT0001 [ 5412.680120] LustreError: 153737:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 5412.809105] LustreError: lustre-MDT0001-osp-MDT0000: operation out_update to node 0@lo failed: rc = -107 [ 5412.812629] 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 [ 5412.833727] Lustre: Skipped 1 previous similar message [ 5412.845162] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5413.132325] Lustre: server umount lustre-MDT0001 complete [ 5415.840176] LustreError: 153736:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 5429.115621] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5429.442987] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5434.875518] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5434.883599] Lustre: Skipped 1 previous similar message [ 5434.896518] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5434.927547] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5435.016897] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:97) [ 5435.021707] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:97) [ 5435.024099] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5446.048763] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 10:17:50 (1789136270) [ 5464.000648] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 5484.318783] Lustre: 156459:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5508.684604] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5513.182321] Lustre: 157593:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5538.366981] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 10:19:23 (1789136363) [ 5539.972238] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 5541.963520] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 10:19:27 (1789136367) [ 5548.098468] Lustre: *** cfs_fail_loc=1631, val=0*** [ 5562.338246] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5562.347286] 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 [ 5562.366556] Lustre: Skipped 2 previous similar messages [ 5562.386843] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5565.602875] Lustre: server umount lustre-MDT0000 complete [ 5569.228269] LustreError: 124623:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789136395 with bad export cookie 136827368170042942 [ 5569.229130] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5569.241157] LustreError: 124623:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 5569.956806] Lustre: server umount lustre-MDT0001 complete [ 5584.727221] Lustre: server umount lustre-OST0000 complete [ 5588.640078] Lustre: 106879:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789136399/real 1789136399] req@ffff8a7a03216940 x1876043673297536/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789136415 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5589.282410] Lustre: 106882:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789136400/real 1789136400] req@ffff8a7b05966580 x1876043673297920/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789136416 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5590.148445] Lustre: server umount lustre-OST0001 complete [ 5608.651570] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 5620.849244] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5627.089945] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5637.084841] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5643.385424] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5646.512489] Lustre: 161492:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5654.873728] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5661.928817] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5662.341736] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:129) [ 5666.423315] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 5672.186670] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5677.584420] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:129) [ 5677.586451] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 5680.633144] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5691.269874] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5696.794045] Lustre: 163367:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5707.191919] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 10:22:12 (1789136532) [ 5709.197918] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 5711.456745] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 10:22:16 (1789136536) [ 5713.591435] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 5715.627726] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 10:22:20 (1789136540) [ 5716.988716] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 5718.585564] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 10:22:24 (1789136544) [ 5729.912574] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 10:22:35 (1789136555) [ 5745.300920] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 10:22:50 (1789136570) [ 5762.506234] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 10:23:07 (1789136587) [ 5783.547132] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 10:23:28 (1789136608) [ 5809.485504] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 10:23:54 (1789136634) [ 5843.704710] Lustre: *** cfs_fail_loc=1632, val=0*** [ 5859.168297] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 10:24:44 (1789136684) [ 5863.656443] Lustre: Failing over lustre-MDT0001 [ 5864.073736] Lustre: server umount lustre-MDT0001 complete [ 5865.848705] LustreError: 162115:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.202.41@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5865.869725] LustreError: 162115:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 28 previous similar messages [ 5866.977878] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5867.001491] Lustre: Skipped 5 previous similar messages [ 5873.521950] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5874.194671] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5874.200599] Lustre: Skipped 5 previous similar messages [ 5874.264353] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5874.264818] Lustre: lustre-MDT0001: Aborting client recovery [ 5874.284117] LustreError: 167154:0:(ldlm_lib.c:3067:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 5874.288821] LustreError: 167178:0:(lod_dev.c:511:lod_sub_recovery_thread()) lustre-MDT0001-osd: get update log duration 0, retries 0, failed: rc = -108 [ 5874.294134] Lustre: 167180:0:(ldlm_lib.c:2467:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 5874.319014] Lustre: 167180:0:(genops.c:1601:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 6c15040c-4b21-4f3a-9e2d-88dd859fc023@ [ 5874.334776] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 5874.357969] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 5874.374544] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 5874.468619] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 5874.477931] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:161) [ 5879.080203] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5879.266231] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 5879.284887] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5879.299555] Lustre: Skipped 3 previous similar messages [ 5883.615361] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 5887.857050] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 5888.334659] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 5896.820655] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 10:25:22 (1789136722) [ 5899.225229] Lustre: 160344:0:(osd_internal.h:1463:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 5899.238746] Lustre: 160344:0:(osd_internal.h:1463:osd_trans_exec_op()) Skipped 1707 previous similar messages [ 5899.247662] Lustre: 160344:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 5899.259717] Lustre: 160344:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1708 previous similar messages [ 5899.273225] Lustre: 160344:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 5899.281579] Lustre: 160344:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1708 previous similar messages [ 5899.288754] Lustre: 160344:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 5899.305016] Lustre: 160344:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1708 previous similar messages [ 5899.314200] Lustre: 160344:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 5899.318984] Lustre: 160344:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1708 previous similar messages [ 5899.325225] Lustre: 160344:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 5899.338413] Lustre: 160344:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1708 previous similar messages [ 5907.740965] Lustre: *** cfs_fail_loc=1600, val=3*** [ 5911.215924] Lustre: Failing over lustre-MDT0000 [ 5911.475641] Lustre: server umount lustre-MDT0000 complete [ 5915.120024] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5921.878710] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5922.060043] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5922.547744] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5922.557675] Lustre: Skipped 2 previous similar messages [ 5923.915379] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5927.912058] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5927.929455] Lustre: Skipped 1 previous similar message [ 5927.974530] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 5928.052597] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 5928.059641] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 5928.270593] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5939.239747] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 10:26:04 (1789136764) [ 5968.067929] Lustre: Failing over lustre-OST0000 [ 5968.264443] Lustre: server umount lustre-OST0000 complete [ 5975.401435] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5986.536581] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5986.876677] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 5988.167775] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 5988.471664] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 5993.797530] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6001.418209] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 6001.666465] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 6007.068565] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 6007.425352] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 6014.146673] Lustre: DEBUG MARKER: oleg241-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff92f06fa7b000.ost_server_uuid 50 [ 6015.643877] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff92f06fa7b000.ost_server_uuid in FULL state after 0 sec [ 6071.266963] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 6071.279213] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6071.282909] Lustre: Skipped 3 previous similar messages [ 6073.826238] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6073.832467] Lustre: Skipped 1 previous similar message [ 6077.372611] Lustre: server umount lustre-MDT0000 complete [ 6088.795107] LustreError: 160329:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789136915 with bad export cookie 136827368170125759 [ 6088.800883] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6088.809447] LustreError: 160329:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 6089.138512] Lustre: server umount lustre-MDT0001 complete [ 6104.545034] Lustre: 106879:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789136915/real 1789136915] req@ffff8a7b3c9b4780 x1876043673695360/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789136931 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6108.578296] Lustre: 106881:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789136919/real 1789136919] req@ffff8a7b0a2d4b40 x1876043673695744/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789136935 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6110.844170] Lustre: server umount lustre-OST0000 complete [ 6114.784277] Lustre: 106882:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789136925/real 1789136925] req@ffff8a7b3c9b70c0 x1876043673696384/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789136941 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6114.821589] Lustre: 106882:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 6120.732478] Lustre: server umount lustre-OST0001 complete [ 6141.389790] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 6144.985195] Key type lgssc unregistered [ 6145.441776] LNet: 176306:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6145.451809] LNetError: 176306:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6146.472602] LNet: Removed LNI 192.168.202.141@tcp [ 6148.143156] Key type .llcrypt unregistered [ 6148.146051] Key type ._llcrypt unregistered [ 6175.317193] Key type ._llcrypt registered [ 6175.322212] Key type .llcrypt registered [ 6175.508058] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_hostid [ 6194.366459] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 6196.128728] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 6196.360499] alg: No test for adler32 (adler32-zlib) [ 6197.715568] Lustre: Lustre: Build Version: 2.17.57_132_gd76390e [ 6198.232449] LNet: Added LNI 192.168.202.141@tcp [8/256/0/180] [ 6200.056274] Key type lgssc registered [ 6201.598414] Lustre: Echo OBD driver; http://www.lustre.org/ [ 6263.283362] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing load_modules_local [ 6277.973318] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 6278.016854] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6279.318950] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 6279.355882] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 6279.481263] Lustre: lustre-MDT0000: new disk, initializing [ 6279.580383] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6279.606379] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 6285.149520] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6300.388214] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6300.488978] Lustre: 180764:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 6300.514417] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 6300.520434] Lustre: Skipped 1 previous similar message [ 6300.577311] Lustre: lustre-MDT0001: new disk, initializing [ 6300.642111] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6300.681097] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 6300.694087] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 6306.080688] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6312.590267] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 6323.776441] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6324.182959] Lustre: lustre-OST0000: new disk, initializing [ 6324.187977] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 6324.202421] Lustre: 182707:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6324.321163] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6331.954079] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 6331.970927] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 6332.082509] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 6332.377785] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6348.742528] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6348.946609] Lustre: lustre-OST0001: new disk, initializing [ 6348.953379] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6348.962859] Lustre: 183733:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 6349.068778] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 6354.985186] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6354.998844] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6355.221748] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6357.395794] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6371.249261] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6382.365441] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6390.862684] Lustre: Setting parameter lustre.lod.lustre-MDT0000-mdtlov.enable_compr_rotational=1 in log params [ 6398.222691] Lustre: Setting parameter lustre.lod.lustre-MDT0001-mdtlov.enable_compr_rotational=1 in log params [ 6405.717442] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 10:33:50 (1789137230) === [ 6407.748594] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 6093 sec ========= 10:33:52 (1789137232) [ 6411.389086] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 10:33:56 (1789137236) === [ 6416.771833] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 10:34:01 (1789137241) === [ 6421.985186] 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 [ 6421.997343] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6421.999950] Lustre: Skipped 3 previous similar messages [ 6422.004551] Lustre: Skipped 2 previous similar messages [ 6427.108148] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6427.120050] Lustre: Skipped 4 previous similar messages [ 6428.347673] Lustre: server umount lustre-MDT0000 complete [ 6437.356462] LustreError: 184262:0:(ldlm_lib.c:1228: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. [ 6437.379959] LustreError: 184262:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 8 previous similar messages [ 6437.427110] LustreError: 180756:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789137264 with bad export cookie 13150877419658388482 [ 6437.427619] LustreError: MGC192.168.202.141@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6437.439039] LustreError: 180756:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 6437.810104] Lustre: server umount lustre-MDT0001 complete [ 6458.519829] Lustre: server umount lustre-OST0000 complete [ 6458.657622] Lustre: 177922:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789137269/real 1789137269] req@ffff8a7b10129680 x1876046144186240/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789137285 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6458.683895] 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 [ 6464.032541] Lustre: 177921:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789137274/real 1789137274] req@ffff8a7b36469680 x1876046144186624/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789137290 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6469.095091] Lustre: 177923:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789137279/real 1789137279] req@ffff8a7b10128b40 x1876046144186880/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789137295 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6469.459964] Lustre: server umount lustre-OST0001 complete [ 6487.404310] Lustre: DEBUG MARKER: oleg241-server.virtnet: executing unload_modules_local [ 6490.238996] Key type lgssc unregistered [ 6490.512779] LNet: 187906:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6490.522598] LNetError: 187906:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6490.541311] LNet: Removed LNI 192.168.202.141@tcp [ 6491.328190] Key type .llcrypt unregistered [ 6491.330601] Key type ._llcrypt unregistered