[ 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 531149643 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2895240K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K 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.001018] APIC: Switch to symmetric I/O mode setup [ 0.003277] x2apic enabled [ 0.004011] Switched APIC routing to physical x2apic. [ 0.005021] kvm-guest: setup PV IPIs [ 0.007845] ..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.008040] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009023] pid_max: default: 32768 minimum: 301 [ 0.010248] LSM: Security Framework initializing [ 0.011098] Yama: becoming mindful. [ 0.012080] SELinux: Initializing. [ 0.013139] *** VALIDATE selinux *** [ 0.021466] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026827] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028178] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029138] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030191] *** VALIDATE tmpfs *** [ 0.032500] *** VALIDATE proc *** [ 0.034213] *** VALIDATE cgroup *** [ 0.035020] *** VALIDATE cgroup2 *** [ 0.036357] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037189] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.038017] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.039043] Spectre V2 : User space: Vulnerable [ 0.040018] Speculative Store Bypass: Vulnerable [ 0.043865] debug: unmapping init [mem 0xffffffffaa859000-0xffffffffaa860fff] [ 0.046259] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.047795] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.048037] ... version: 2 [ 0.049038] ... bit width: 48 [ 0.050019] ... generic registers: 4 [ 0.051020] ... value mask: 0000ffffffffffff [ 0.052027] ... max period: 00007fffffffffff [ 0.053025] ... fixed-purpose events: 3 [ 0.054021] ... event mask: 000000070000000f [ 0.055399] rcu: Hierarchical SRCU implementation. [ 0.057806] smp: Bringing up secondary CPUs ... [ 0.058769] x86: Booting SMP configuration: [ 0.059053] .... node #0, CPUs: #1 #2 #3 [ 0.063703] smp: Brought up 1 node, 4 CPUs [ 0.066033] smpboot: Max logical packages: 1 [ 0.067023] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.221000] node 0 deferred pages initialised in 152ms [ 0.225104] devtmpfs: initialized [ 0.226289] x86/mm: Memory block size: 128MB [ 0.228000] gcov: version magic: 0x41383552 [ 0.230336] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.234145] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.236349] pinctrl core: initialized pinctrl subsystem [ 0.239219] [ 0.239755] ************************************************************* [ 0.241014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.244021] ** ** [ 0.246016] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.248016] ** ** [ 0.251017] ** This means that this kernel is built to expose internal ** [ 0.253014] ** IOMMU data structures, which may compromise security on ** [ 0.255018] ** your system. ** [ 0.257019] ** ** [ 0.260018] ** If you see this message and you are not debugging the ** [ 0.262017] ** kernel, report this immediately to your vendor! ** [ 0.264017] ** ** [ 0.266016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.268016] ************************************************************* [ 0.270758] NET: Registered protocol family 16 [ 0.272468] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.275071] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.278086] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.282036] cpuidle: using governor menu [ 0.283611] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.285549] PCI: Using configuration type 1 for base access [ 0.287099] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.295179] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.298083] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.300157] cryptd: max_cpu_qlen set to 1000 [ 0.303328] ACPI: Added _OSI(Module Device) [ 0.305019] ACPI: Added _OSI(Processor Device) [ 0.306014] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.308014] ACPI: Added _OSI(Processor Aggregator Device) [ 0.312313] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.318533] ACPI: Interpreter enabled [ 0.319063] ACPI: PM: (supports S0 S3 S4 S5) [ 0.320010] ACPI: Using IOAPIC for interrupt routing [ 0.321093] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.323362] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.332418] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.335047] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.338023] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.341105] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.346416] acpiphp: Slot [2] registered [ 0.348184] acpiphp: Slot [5] registered [ 0.349133] acpiphp: Slot [6] registered [ 0.351164] acpiphp: Slot [7] registered [ 0.353163] acpiphp: Slot [8] registered [ 0.354138] acpiphp: Slot [9] registered [ 0.356156] acpiphp: Slot [10] registered [ 0.357159] acpiphp: Slot [3] registered [ 0.359168] acpiphp: Slot [4] registered [ 0.360138] acpiphp: Slot [11] registered [ 0.362132] acpiphp: Slot [12] registered [ 0.363115] acpiphp: Slot [13] registered [ 0.365090] acpiphp: Slot [14] registered [ 0.365937] acpiphp: Slot [15] registered [ 0.366059] acpiphp: Slot [16] registered [ 0.366926] acpiphp: Slot [17] registered [ 0.368078] acpiphp: Slot [18] registered [ 0.368930] acpiphp: Slot [19] registered [ 0.370071] acpiphp: Slot [20] registered [ 0.371107] acpiphp: Slot [21] registered [ 0.373105] acpiphp: Slot [22] registered [ 0.374089] acpiphp: Slot [23] registered [ 0.375063] acpiphp: Slot [24] registered [ 0.376114] acpiphp: Slot [25] registered [ 0.377066] acpiphp: Slot [26] registered [ 0.377889] acpiphp: Slot [27] registered [ 0.378071] acpiphp: Slot [28] registered [ 0.379030] acpiphp: Slot [29] registered [ 0.380052] acpiphp: Slot [30] registered [ 0.380954] acpiphp: Slot [31] registered [ 0.382048] PCI host bridge to bus 0000:00 [ 0.383016] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.384018] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.386017] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.387020] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.389020] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.391027] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.393194] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.396153] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.398149] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.406020] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.411621] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.413033] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.414014] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.416018] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.417407] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.421142] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.424052] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.426821] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.432019] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.444023] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.450022] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.456751] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.463023] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.472023] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.488019] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.497122] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.508020] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.515023] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.529016] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.541098] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.548017] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.554018] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.569021] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.578865] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.586027] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.593022] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.607041] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.619383] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.628028] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.636026] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.658023] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.667994] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.675022] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.683023] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.698017] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.708100] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.710354] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.713306] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.715289] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.716236] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.722163] iommu: Default domain type: Passthrough [ 0.724484] SCSI subsystem initialized [ 0.726175] ACPI: bus type USB registered [ 0.727137] usbcore: registered new interface driver usbfs [ 0.729096] usbcore: registered new interface driver hub [ 0.730077] usbcore: registered new device driver usb [ 0.732207] pps_core: LinuxPPS API ver. 1 registered [ 0.734015] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.737078] PTP clock support registered [ 0.740061] EDAC MC: Ver: 3.0.0 [ 0.742196] PCI: Using ACPI for IRQ routing [ 0.744297] NetLabel: Initializing [ 0.745027] NetLabel: domain hash size = 128 [ 0.746018] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.748129] NetLabel: unlabeled traffic allowed by default [ 0.750127] vgaarb: loaded [ 0.751239] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.752011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.758277] clocksource: Switched to clocksource kvm-clock [ 0.869813] VFS: Disk quotas dquot_6.6.0 [ 0.871110] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.872694] *** VALIDATE ramfs *** [ 0.873463] *** VALIDATE hugetlbfs *** [ 0.874662] pnp: PnP ACPI init [ 0.876454] pnp: PnP ACPI: found 6 devices [ 0.891986] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.895380] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.897086] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.898671] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.900120] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.901943] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.903725] NET: Registered protocol family 2 [ 0.905653] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.909207] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.911812] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.917686] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.921643] TCP: Hash tables configured (established 65536 bind 65536) [ 0.925035] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.928128] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.931312] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.934396] NET: Registered protocol family 1 [ 0.937208] RPC: Registered named UNIX socket transport module. [ 0.939543] RPC: Registered udp transport module. [ 0.941571] RPC: Registered tcp transport module. [ 0.943571] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.946291] NET: Registered protocol family 44 [ 0.947525] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.949280] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.950808] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.953036] PCI: CLS 0 bytes, default 64 [ 0.954593] Unpacking initramfs... [ 2.391382] debug: unmapping init [mem 0xffff8d737cc54000-0xffff8d737ffbffff] [ 2.396725] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.400135] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.404531] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.914453] Initialise system trusted keyrings [ 2.917020] Key type blacklist registered [ 2.919641] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.929946] zbud: loaded [ 2.933339] *** VALIDATE nfs *** [ 2.934632] *** VALIDATE nfs4 *** [ 2.936363] pstore: using deflate compression [ 2.940309] Platform Keyring initialized [ 3.042156] NET: Registered protocol family 38 [ 3.044147] Key type asymmetric registered [ 3.045587] Asymmetric key parser 'x509' registered [ 3.047645] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.051105] io scheduler mq-deadline registered [ 3.052485] io scheduler kyber registered [ 3.053754] io scheduler bfq registered [ 3.055342] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.058333] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.061520] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.064619] ACPI: Power Button [PWRF] [ 3.069926] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.078823] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.093651] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.101281] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.118688] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.146846] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.177658] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.183924] Non-volatile memory driver v1.3 [ 3.186339] Linux agpgart interface v0.103 [ 3.221876] virtio_blk virtio1: [vda] 146608 512-byte logical blocks (75.1 MB/71.6 MiB) [ 3.224517] vda: detected capacity change from 0 to 75063296 [ 3.239140] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.242359] vdb: detected capacity change from 0 to 1073741824 [ 3.257266] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.259078] vdc: detected capacity change from 0 to 2621440000 [ 3.270312] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.273162] vdd: detected capacity change from 0 to 2621440000 [ 3.286113] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.287967] vde: detected capacity change from 0 to 4294967296 [ 3.301824] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.305122] vdf: detected capacity change from 0 to 4294967296 [ 3.317596] libphy: Fixed MDIO Bus: probed [ 3.336544] usbcore: registered new interface driver usbserial_generic [ 3.338978] usbserial: USB Serial support registered for generic [ 3.341773] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.347431] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.350036] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.353430] mousedev: PS/2 mouse device common for all mice [ 3.356723] rtc_cmos 00:05: RTC can wake from S4 [ 3.359903] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.364982] rtc_cmos 00:05: registered as rtc0 [ 3.366726] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.369265] intel_pstate: CPU model not supported [ 3.370160] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.376367] hid: raw HID events driver (C) Jiri Kosina [ 3.377286] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.378303] usbcore: registered new interface driver usbhid [ 3.385056] usbhid: USB HID core driver [ 3.386489] drop_monitor: Initializing network drop monitor service [ 3.389724] Initializing XFRM netlink socket [ 3.392230] NET: Registered protocol family 10 [ 3.395536] Segment Routing with IPv6 [ 3.396564] NET: Registered protocol family 17 [ 3.398470] mpls_gso: MPLS GSO support [ 3.405269] RAS: Correctable Errors collector initialized. [ 3.407550] AVX version of gcm_enc/dec engaged. [ 3.408876] AES CTR mode by8 optimization enabled [ 3.482968] sched_clock: Marking stable (3482940206, 0)->(4451011605, -968071399) [ 3.485016] registered taskstats version 1 [ 3.486257] Loading compiled-in X.509 certificates [ 3.487371] zswap: loaded using pool lzo/zbud [ 3.509282] Key type big_key registered [ 3.519106] Key type encrypted registered [ 3.520109] ima: No TPM chip found, activating TPM-bypass! [ 3.521169] ima: Allocated hash algorithm: sha1 [ 3.522077] ima: No architecture policies found [ 3.523084] evm: Initialising EVM extended attributes: [ 3.523961] evm: security.selinux [ 3.525144] evm: security.ima [ 3.526143] evm: security.capability [ 3.526856] evm: HMAC attrs: 0x1 [ 3.529183] rtc_cmos 00:05: setting system clock to 2026-08-26 23:27:53 UTC (1787786873) [ 3.533251] debug: unmapping init [mem 0xffffffffab803000-0xffffffffab9fffff] [ 3.535124] debug: unmapping init [mem 0xffffffffaa582000-0xffffffffaa858fff] [ 3.543106] Write protecting the kernel read-only data: 28672k [ 3.546866] debug: unmapping init [mem 0xffffffffa8c03000-0xffffffffa8dfffff] [ 3.548960] debug: unmapping init [mem 0xffffffffa9514000-0xffffffffa95fffff] [ 3.577781] 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.582809] systemd[1]: Detected virtualization kvm. [ 3.584120] systemd[1]: Detected architecture x86-64. [ 3.585296] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.608109] systemd[1]: No hostname configured. [ 3.609195] systemd[1]: Set hostname to . [ 3.610630] random: systemd: uninitialized urandom read (16 bytes read) [ 3.612894] systemd[1]: Initializing machine ID from random generator. [ 3.657584] random: ln: uninitialized urandom read (6 bytes read) [ 3.727322] random: systemd: uninitialized urandom read (16 bytes read) [ 3.730102] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 3.734492] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 3.738222] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Paths. [ OK ] Reached target Timers. [ OK ] Reached target Slices. Starting Apply Kernel Variables... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.280160] device-mapper: uevent: version 1.0.3 [ 4.281758] 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... [ 4.951257] virtio_net virtio0 ens2: renamed from eth0 [ 4.968948] random: fast init done [ 5.077505] scsi host0: ata_piix [ 5.092382] scsi host1: ata_piix [ 5.094160] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.097220] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.738951] dracut-initqueue[581]: RTNETLINK answers: File exists [ 10.052219] random: crng init done [ 10.054172] 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.359103] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. Stopping udev Kernel Device Manager... [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.417532] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.694348] SELinux: Disabled at runtime. [ 11.759778] 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) [ 11.767381] systemd[1]: Detected virtualization kvm. [ 11.768661] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.261460] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.264580] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.269470] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.272429] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.274832] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.283513] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.287530] systemd[1]: Reached target rpc_pipefs.target. [ OK ] Reached target rpc_pipefs.target. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Control Socket. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Stopped target Initrd File Systems. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice User and Session Slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. Mounting Kernel Debug File System... [ OK ] Listening on initctl Compatibility Named Pipe. Mounting POSIX Message Queue File System... [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Reached target Paths. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Mounting Huge Pages File System... [ OK ] Created slice system-getty.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 ] Reached target Slices. Starting Apply Kernel Variables... Starting Remount Root and Kernel File Systems... [ 12.464345] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 12.730164] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.042076] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.076936] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.183802] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.204992] EDAC sbridge: Ver: 1.1.2 [ 14.483210] Key type dns_resolver registered [ 14.774858] NFS: Registering the id_resolver key type [ 14.776864] Key type id_resolver registered [ 14.778474] 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 update of the root trust anchor for DNSSEC. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started 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 oleg105-server login: [ 32.582503] spl: loading out-of-tree module taints kernel. [ 35.106704] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 39.826529] Key type ._llcrypt registered [ 39.828258] Key type .llcrypt registered [ 39.879478] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_hostid [ 48.010633] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 48.580712] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 48.589180] alg: No test for adler32 (adler32-zlib) [ 49.622677] Lustre: Lustre: Build Version: 2.17.57_52_gc224de1 [ 49.958413] LNet: Added LNI 192.168.201.105@tcp [8/256/0/180] [ 51.599245] Key type lgssc registered [ 52.316492] Lustre: Echo OBD driver; http://www.lustre.org/ [ 60.677858] vdc: vdc1 vdc9 [ 60.962271] hrtimer: interrupt took 7262026 ns [ 71.729340] vde: vde1 vde9 [ 82.640926] vdf: vdf1 vdf9 [ 101.615648] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 113.213417] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 114.658700] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 115.296562] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 115.522912] Lustre: lustre-MDT0000: new disk, initializing [ 116.430101] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 116.546382] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 123.370675] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 129.879985] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 138.177924] Lustre: lustre-OST0000: new disk, initializing [ 138.180343] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 138.182801] Lustre: Skipped 1 previous similar message [ 138.283297] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 138.764291] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 138.775294] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 139.000204] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 145.799402] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 159.897343] Lustre: lustre-OST0001: new disk, initializing [ 159.915187] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 160.209222] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 167.079126] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 167.084849] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 167.166902] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 167.250741] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 179.305791] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 187.263106] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 195.829262] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing check_logdir /tmp/testlogs/ [ 201.529857] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing yml_node [ 205.370338] Lustre: DEBUG MARKER: Client: 2.17.57.52 [ 208.571025] Lustre: DEBUG MARKER: MDS: 2.17.57.52 [ 211.494963] Lustre: DEBUG MARKER: OSS: 2.17.57.52 [ 213.015923] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Wed Aug 26 19:31:20 EDT 2026 [ 234.508644] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 245.601534] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 253.923634] 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 [ 253.924991] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 253.945593] Lustre: Skipped 1 previous similar message [ 255.649484] Lustre: server umount lustre-MDT0000 complete [ 260.064564] LustreError: 5806:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787787130 with bad export cookie 12437920577864947467 [ 260.070107] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 260.079492] LustreError: 5806:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 260.172823] Lustre: server umount lustre-OST0000 complete [ 265.025905] Lustre: server umount lustre-OST0001 complete [ 278.308383] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing unload_modules_local [ 282.108066] Key type lgssc unregistered [ 282.470604] LNet: 11658:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 282.482843] LNetError: 11658:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 282.496933] LNet: Removed LNI 192.168.201.105@tcp [ 283.434403] Key type .llcrypt unregistered [ 283.438833] Key type ._llcrypt unregistered [ 304.361607] Key type ._llcrypt registered [ 304.369203] Key type .llcrypt registered [ 304.619360] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_hostid [ 320.892892] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 322.343028] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 322.494036] alg: No test for adler32 (adler32-zlib) [ 323.648684] Lustre: Lustre: Build Version: 2.17.57_52_gc224de1 [ 324.037785] LNet: Added LNI 192.168.201.105@tcp [8/256/0/180] [ 325.815521] Key type lgssc registered [ 326.899467] Lustre: Echo OBD driver; http://www.lustre.org/ [ 336.720802] vdc: vdc1 vdc9 [ 336.751705] vdc: vdc1 vdc9 [ 336.798273] vdc: vdc1 vdc9 [ 348.000236] vde: vde1 vde9 [ 358.907978] vdf: vdf1 vdf9 [ 381.038676] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 392.879038] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 394.765093] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 394.960218] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 395.044813] Lustre: lustre-MDT0000: new disk, initializing [ 395.723885] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 395.818397] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 401.303525] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 408.459207] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 416.039753] Lustre: lustre-OST0000: new disk, initializing [ 416.042670] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 416.045551] Lustre: Skipped 1 previous similar message [ 416.130821] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 416.809358] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 416.819482] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 417.013766] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 423.893764] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 437.724361] Lustre: lustre-OST0001: new disk, initializing [ 437.732443] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 437.940052] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 446.234472] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 446.736620] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 446.741537] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 446.882136] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 457.340308] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 469.537859] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 477.228605] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 19:35:44 (1787787344) === [ 480.495433] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 19:35:47 (1787787347) [ 489.368801] Lustre: *** cfs_fail_loc=1600, val=3*** [ 494.293314] Lustre: *** cfs_fail_loc=1600, val=3*** [ 508.725881] Lustre: server umount lustre-MDT0000 complete [ 513.561047] LustreError: 15464:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787787383 with bad export cookie 11364138024256438510 [ 513.577770] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 523.822118] Lustre: server umount lustre-OST0000 complete [ 528.352088] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787787382/real 1787787382] req@ffff8d72cc11bc00 x1874630743753344/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787787398 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 528.408700] 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 [ 529.065596] Lustre: server umount lustre-OST0001 complete [ 540.057597] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 19:36:48 (1787787408) [ 555.822586] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 568.019245] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 574.151967] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 577.694307] Lustre: 21386:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 586.020944] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 592.132858] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:40 to 0x240000400:65) [ 594.387624] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 597.474493] LustreError: 21746:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 597.516627] LustreError: 21746:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 602.611643] LustreError: 21747:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 605.666966] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 610.825681] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 613.244702] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 622.190995] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 626.479540] Lustre: 23291:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 634.744362] Lustre: *** cfs_fail_loc=1501, val=0*** [ 653.240915] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 19:38:40 (1787787520) [ 655.143837] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_1b OI Scrub not implemented for ZFS [ 656.940546] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 19:38:44 (1787787524) [ 665.042117] Lustre: *** cfs_fail_loc=1504, val=0*** [ 665.054740] Lustre: *** cfs_fail_loc=1504, val=0*** [ 684.863791] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 19:39:12 (1787787552) [ 693.453206] Lustre: *** cfs_fail_loc=1603, val=0*** [ 710.154754] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 19:39:37 (1787787577) [ 718.958624] Lustre: *** cfs_fail_loc=1604, val=0*** [ 736.576657] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 19:40:04 (1787787604) [ 744.696559] Lustre: *** cfs_fail_loc=1605, val=0*** [ 760.449853] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 19:40:28 (1787787628) [ 768.837935] Lustre: *** cfs_fail_loc=161d, val=0*** [ 785.831546] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 19:40:53 (1787787653) [ 787.826769] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_2e needs >= 2 MDTs [ 789.582744] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 19:40:57 (1787787657) [ 797.812430] Lustre: *** cfs_fail_loc=1603, val=0*** [ 799.228287] Lustre: *** cfs_fail_loc=1604, val=0*** [ 812.976387] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 19:41:20 (1787787680) [ 815.149267] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_4 OI Scrub not implemented for ZFS [ 817.892600] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 19:41:25 (1787787685) [ 820.205259] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_5 OI Scrub not implemented for ZFS [ 823.325868] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 19:41:30 (1787787690) [ 833.676564] Lustre: *** cfs_fail_loc=1600, val=1*** [ 835.745354] Lustre: *** cfs_fail_loc=1600, val=1*** [ 835.747112] Lustre: Skipped 1 previous similar message [ 839.839500] Lustre: *** cfs_fail_loc=1608, val=1*** [ 839.847449] Lustre: Skipped 3 previous similar messages [ 857.115384] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 19:42:04 (1787787724) [ 867.351326] Lustre: *** cfs_fail_loc=1601, val=1*** [ 867.357107] Lustre: Skipped 4 previous similar messages [ 883.872387] Lustre: *** cfs_fail_loc=1601, val=1*** [ 883.878389] Lustre: Skipped 11 previous similar messages [ 894.020436] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 19:42:41 (1787787761) [ 930.448339] Lustre: *** cfs_fail_loc=1601, val=1*** [ 930.453259] Lustre: Skipped 1 previous similar message [ 936.815205] Lustre: Failing over lustre-MDT0000 [ 937.279394] Lustre: server umount lustre-MDT0000 complete [ 947.993468] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 948.233351] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 948.360340] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 948.505025] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:455 to 0x240000400:481) [ 948.524569] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:455 to 0x280000400:481) [ 953.113422] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 953.328214] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 954.337018] Lustre: 12932:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787787808/real 1787787808] req@ffff8d72cacf83c0 x1874630744216448/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787787824 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 959.462782] Lustre: 12930:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787787813/real 1787787813] req@ffff8d72caf283c0 x1874630744216704/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787787829 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 959.522250] Lustre: 12930:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 964.639447] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 19:43:52 (1787787832) [ 981.630587] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 996.740172] Lustre: 31324:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1022.038821] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1026.427639] Lustre: 32267:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1036.057052] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1039.724116] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1040.743378] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1041.761231] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1043.819849] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1043.836306] Lustre: Skipped 1 previous similar message [ 1045.914823] Lustre: Failing over lustre-MDT0000 [ 1046.764721] Lustre: server umount lustre-MDT0000 complete [ 1059.607683] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1060.195922] 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 [ 1060.216512] Lustre: Skipped 2 previous similar messages [ 1060.558037] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1060.879755] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:531 to 0x240000400:577) [ 1060.888405] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:530 to 0x280000400:545) [ 1065.442881] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1065.464240] Lustre: Skipped 1 previous similar message [ 1066.466754] Lustre: 12929:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787787920/real 1787787920] req@ffff8d72cd414f00 x1874630744286208/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787787936 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1066.518835] Lustre: 12929:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 1067.268419] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1071.584282] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787787925/real 1787787925] req@ffff8d72cf1f92c0 x1874630744286592/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787787941 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1081.220283] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 19:45:48 (1787787948) [ 1084.162579] Lustre: server umount lustre-MDT0000 complete [ 1088.800442] LustreError: 20940:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787787958 with bad export cookie 11364138024256598418 [ 1088.811460] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1098.330710] Lustre: server umount lustre-OST0000 complete [ 1101.087330] Lustre: 12930:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787787955/real 1787787955] req@ffff8d72cb7fc000 x1874630744299648/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787787971 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1101.135847] Lustre: 12930:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1101.157699] 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 [ 1104.539229] Lustre: server umount lustre-OST0001 complete [ 1114.437908] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_hostid [ 1124.748349] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 1139.099057] vdc: vdc1 vdc9 [ 1152.244135] vde: vde1 vde9 [ 1165.270511] vdf: vdf1 vdf9 [ 1185.065170] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 1197.370334] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1197.567625] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1197.665048] Lustre: lustre-MDT0000: new disk, initializing [ 1198.098291] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1198.177336] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1203.587471] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1209.323979] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1218.146913] Lustre: lustre-OST0000: new disk, initializing [ 1218.153628] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1218.177109] Lustre: Skipped 1 previous similar message [ 1220.073389] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 1220.076576] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 1220.415892] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 1227.921672] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1240.489606] Lustre: lustre-OST0001: new disk, initializing [ 1240.496561] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1242.362350] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 1242.367381] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 1242.482843] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 1247.523985] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1257.183259] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1261.074241] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1274.862387] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1275.902291] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1275.908732] Lustre: Skipped 19 previous similar messages [ 1281.604415] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1281.621792] Lustre: Skipped 6 previous similar messages [ 1303.344830] Lustre: Failing over lustre-MDT0000 [ 1303.724620] Lustre: server umount lustre-MDT0000 complete [ 1314.037327] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1314.278327] 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 [ 1314.283955] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 1314.295466] Lustre: Skipped 1 previous similar message [ 1314.620516] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1314.626065] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:43 to 0x240000400:65) [ 1314.629698] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:43 to 0x280000400:65) [ 1319.685229] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1319.916625] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1319.921324] Lustre: Skipped 1 previous similar message [ 1320.416374] Lustre: 12932:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787788174/real 1787788174] req@ffff8d73f52f43c0 x1874630744357760/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787788190 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1328.992504] Lustre: Failing over lustre-MDT0000 [ 1329.417175] Lustre: server umount lustre-MDT0000 complete [ 1339.975935] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1340.200322] 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 [ 1340.211047] Lustre: Skipped 1 previous similar message [ 1340.274748] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1340.279821] Lustre: Skipped 3 previous similar messages [ 1340.361767] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1340.372203] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:43 to 0x240000400:97) [ 1340.388724] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:43 to 0x280000400:97) [ 1345.147199] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1345.527924] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1345.538797] Lustre: Skipped 1 previous similar message [ 1351.235547] Lustre: Failing over lustre-MDT0000 [ 1351.682608] Lustre: server umount lustre-MDT0000 complete [ 1362.911625] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1363.280462] 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 [ 1363.299208] Lustre: Skipped 1 previous similar message [ 1363.631083] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:43 to 0x240000400:129) [ 1363.639936] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:43 to 0x280000400:129) [ 1368.580410] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1368.591153] Lustre: Skipped 1 previous similar message [ 1368.902445] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1371.619197] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787788225/real 1787788225] req@ffff8d72cdc90b40 x1874630744380800/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787788241 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1371.680046] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 1375.222523] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1375.224607] Lustre: Skipped 2 previous similar messages [ 1389.791707] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 19:50:57 (1787788257) [ 1405.437855] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 1417.787433] Lustre: 45603:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1441.605432] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1446.094776] Lustre: 46547:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1575.277370] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 19:54:03 (1787788443) [ 1635.673855] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1635.682507] Lustre: Skipped 4 previous similar messages [ 1663.250688] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1663.252488] Lustre: Skipped 9 previous similar messages [ 1703.849561] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 19:56:11 (1787788571) [ 1705.724767] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_10 lookup(..)/linkea on ZFS issue [ 1707.219432] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 19:56:15 (1787788575) [ 1757.664099] 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 [ 1757.666447] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1757.673601] Lustre: Skipped 1 previous similar message [ 1757.682499] Lustre: Skipped 1 previous similar message [ 1758.162380] Lustre: server umount lustre-MDT0000 complete [ 1762.292412] LustreError: 39750:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787788632 with bad export cookie 11364138024256616310 [ 1762.293366] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1762.298850] LustreError: 39750:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1762.370959] Lustre: server umount lustre-OST0000 complete [ 1766.793288] Lustre: server umount lustre-OST0001 complete [ 1805.154743] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 1810.272359] LustreError: 50225:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.201.105@tcp: failed processing log, type 4: rc = -110 [ 1836.064072] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1836.074876] Lustre: Skipped 1 previous similar message [ 1844.050275] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1848.126585] Lustre: 50813:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1848.147736] Lustre: *** cfs_fail_loc=160e, val=3*** [ 1851.223271] Lustre: 50813:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1860.530230] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 19:58:48 (1787788728) [ 1873.047846] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 1884.410474] LustreError: 50235:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1884.823920] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2733 to 0x240000400:2753) [ 1889.762413] LustreError: 50238:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1890.583171] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1894.360338] Lustre: 52686:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1894.887804] LustreError: 50235:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1901.034846] LustreError: 52275:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1901.058038] LustreError: 52275:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 1906.145461] LustreError: 52271:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1914.392922] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2668 to 0x280000400:2689) [ 1916.451989] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1924.707995] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1928.877287] Lustre: 54104:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1933.962848] Lustre: *** cfs_fail_loc=160d, val=0*** [ 1934.464987] Lustre: *** cfs_fail_loc=160d, val=0*** [ 1934.468165] Lustre: Skipped 6 previous similar messages [ 1941.029589] Lustre: Failing over lustre-OST0000 [ 1941.184307] Lustre: server umount lustre-OST0000 complete [ 1945.064368] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1945.082654] LustreError: 52275:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1950.913740] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1952.111311] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1952.270273] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1952.271095] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1952.278832] Lustre: *** cfs_fail_loc=215, val=0*** [ 1952.281285] Lustre: Skipped 1 previous similar message [ 1957.343725] Lustre: *** cfs_fail_loc=215, val=0*** [ 1958.793883] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1962.488464] Lustre: *** cfs_fail_loc=215, val=0*** [ 1963.970135] Lustre: 55536:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1964.375337] Lustre: 55536:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1967.585368] Lustre: *** cfs_fail_loc=215, val=0*** [ 1967.999917] Lustre: Failing over lustre-OST0000 [ 1968.152676] Lustre: server umount lustre-OST0000 complete [ 1971.708161] LustreError: 50239:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1971.735904] LustreError: 50239:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 1979.614238] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1980.770878] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1980.887421] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1980.898572] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1980.900738] Lustre: *** cfs_fail_loc=215, val=0*** [ 1989.042715] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1991.141818] Lustre: *** cfs_fail_loc=215, val=0*** [ 1991.148865] Lustre: Skipped 1 previous similar message [ 1996.476772] Lustre: server umount lustre-MDT0000 complete [ 2000.618361] LustreError: 50228:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787788870 with bad export cookie 11364138024257217659 [ 2000.633892] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2010.228385] Lustre: server umount lustre-OST0000 complete [ 2024.426759] Lustre: server umount lustre-OST0001 complete [ 2035.021766] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 20:01:42 (1787788902) [ 2036.616395] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_12a needs >= 2 MDTs [ 2038.535468] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 20:01:46 (1787788906) [ 2053.710666] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 2071.328318] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2075.292234] Lustre: 59078:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2090.092756] LustreError: 59442:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2090.122708] LustreError: 59442:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 2090.168128] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2818 to 0x240000400:2849) [ 2090.498242] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2104.870182] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2668 to 0x280000400:2721) [ 2107.656742] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2117.519656] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2124.264247] LustreError: 61050:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-OST0000: can't get bonus, rc = -2 [ 2135.961553] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 20:03:23 (1787789003) [ 2137.210532] Lustre: *** cfs_fail_loc=160f, val=0*** [ 2149.145856] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 20:03:36 (1787789016) [ 2153.072690] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2206.337672] Lustre: server umount lustre-MDT0000 complete [ 2211.300753] LustreError: 60992:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787789081 with bad export cookie 11364138024257225576 [ 2211.317436] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2221.689618] Lustre: server umount lustre-OST0000 complete [ 2223.585624] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787789077/real 1787789077] req@ffff8d73d1735680 x1874630746499200/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787789093 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2223.614422] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 2223.638206] 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 [ 2223.664425] Lustre: Skipped 1 previous similar message [ 2225.584627] Lustre: server umount lustre-OST0001 complete [ 2241.139337] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 2259.102748] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2262.731747] Lustre: 64788:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2262.739796] Lustre: 64788:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2279.070165] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2279.137269] LustreError: 65156:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2279.168526] LustreError: 65156:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 2279.179466] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2946 to 0x240000400:2977) [ 2293.263270] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2723 to 0x280000400:2753) [ 2295.692906] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2302.607502] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2312.623664] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 20:06:20 (1787789180) [ 2317.869615] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2317.873615] Lustre: Skipped 63 previous similar messages [ 2340.161564] Lustre: server umount lustre-MDT0000 complete [ 2344.630176] LustreError: 64343:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787789214 with bad export cookie 11364138024257238029 [ 2354.254252] Lustre: server umount lustre-OST0000 complete [ 2368.325098] Lustre: server umount lustre-OST0001 complete [ 2386.614100] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 2398.065376] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2398.068912] Lustre: Skipped 10 previous similar messages [ 2403.887411] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2420.747937] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2422.394790] LustreError: 70120:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2422.412963] LustreError: 70120:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 1 previous similar message [ 2422.485874] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3074 to 0x240000400:3105) [ 2435.090454] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2723 to 0x280000400:2785) [ 2437.273644] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2445.981512] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2457.179618] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 20:08:45 (1787789325) [ 2461.119949] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2461.255296] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2461.256754] Lustre: Skipped 63 previous similar messages [ 2472.175493] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 20:09:00 (1787789340) [ 2474.522676] Lustre: *** cfs_fail_loc=1612, val=0*** [ 2474.534152] Lustre: Skipped 2 previous similar messages [ 2474.694885] Lustre: *** cfs_fail_loc=1612, val=0*** [ 2486.958928] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 20:09:14 (1787789354) [ 2488.750621] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c needs >= 2 MDTs [ 2491.063800] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 20:09:18 (1787789358) [ 2493.045863] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15d needs >= 2 MDTs [ 2494.967342] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 20:09:22 (1787789362) [ 2498.411300] Lustre: *** cfs_fail_loc=1613, val=0*** [ 2509.039383] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 20:09:36 (1787789376) [ 2511.348842] Lustre: *** cfs_fail_loc=1614, val=0*** [ 2511.355630] Lustre: Skipped 2 previous similar messages [ 2522.426498] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 20:09:50 (1787789390) [ 2524.991876] Lustre: *** cfs_fail_loc=1615, val=0*** [ 2524.997179] Lustre: Skipped 1 previous similar message [ 2540.498478] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 2542.416411] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 20:10:10 (1787789410) [ 2544.504951] Lustre: *** cfs_fail_loc=1617, val=0*** [ 2544.509152] Lustre: Skipped 3 previous similar messages [ 2544.724966] Lustre: *** cfs_fail_loc=1617, val=0*** [ 2544.728075] Lustre: Skipped 1 previous similar message [ 2546.765893] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2546.768512] Lustre: Skipped 3 previous similar messages [ 2562.330965] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 20:10:29 (1787789429) [ 2564.704083] Lustre: *** cfs_fail_loc=1618, val=0*** [ 2564.710939] Lustre: Skipped 3 previous similar messages [ 2598.879958] 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 [ 2598.912203] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2598.930180] Lustre: Skipped 1 previous similar message [ 2599.427777] Lustre: server umount lustre-MDT0000 complete [ 2604.356300] LustreError: 69308:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787789474 with bad export cookie 11364138024257250643 [ 2604.373485] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2604.382224] LustreError: Skipped 1 previous similar message [ 2604.576311] Lustre: server umount lustre-OST0000 complete [ 2610.637062] Lustre: server umount lustre-OST0001 complete [ 2630.695123] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 2647.683405] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2650.569141] Lustre: 77313:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2650.588292] Lustre: 77313:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 3 previous similar messages [ 2662.556400] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2667.696642] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3225 to 0x240000400:3265) [ 2674.180539] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2792 to 0x280000400:2817) [ 2674.874752] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2682.190164] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2697.571064] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 20:12:45 (1787789565) [ 2699.515504] Lustre: *** cfs_fail_loc=1618, val=0*** [ 2699.520067] Lustre: Skipped 3 previous similar messages [ 2734.504892] Lustre: server umount lustre-MDT0000 complete [ 2737.391314] LustreError: 76865:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787789607 with bad export cookie 11364138024257271622 [ 2737.397767] LustreError: 76865:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2747.978414] Lustre: server umount lustre-OST0000 complete [ 2751.967120] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787789605/real 1787789605] req@ffff8d73d84ade00 x1874630746747008/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787789621 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2753.270697] Lustre: server umount lustre-OST0001 complete [ 2771.163914] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 2787.540805] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2806.696095] LustreError: 82276:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2806.725988] LustreError: 82276:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 2806.753510] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3270 to 0x240000400:3297) [ 2807.475225] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2820.093420] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2792 to 0x280000400:2849) [ 2821.896940] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2828.956644] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2837.559527] Lustre: *** cfs_fail_loc=1602, val=10*** [ 2860.600766] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 20:15:28 (1787789728) [ 2862.316147] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2862.323647] Lustre: Skipped 3 previous similar messages [ 2866.932409] Lustre: *** cfs_fail_loc=161c, val=0*** [ 2882.733829] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 20:15:50 (1787789750) [ 2884.590055] Lustre: *** cfs_fail_loc=162e, val=0*** [ 2884.598743] Lustre: Skipped 3 previous similar messages [ 2896.846745] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 20:16:05 (1787789765) [ 2915.594828] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 20:16:23 (1787789783) [ 2926.921579] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 20:16:34 (1787789794) [ 2930.136366] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2930.164556] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2930.167623] Lustre: Skipped 3 previous similar messages [ 2935.558402] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.201.5@tcp inode [0x200004a51:0x1d:0x0] object 0x240000400:3307 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 2936.720345] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.201.5@tcp inode [0x200004a51:0x1e:0x0] object 0x240000400:3308 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 2944.792305] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 20:16:52 (1787789812) [ 2947.000235] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2947.004992] Lustre: Skipped 3 previous similar messages [ 2992.742616] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 20:17:40 (1787789860) [ 2998.999374] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 20:17:46 (1787789866) [ 3011.609298] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 20:17:59 (1787789879) [ 3013.421185] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_22a needs >= 2 MDTs [ 3014.895425] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 20:18:02 (1787789882) [ 3016.211239] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_22b needs >= 2 MDTs [ 3017.717286] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 20:18:05 (1787789885) [ 3018.970770] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23a needs >= 2 MDTs [ 3020.165647] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 3021.684654] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 20:18:09 (1787789889) [ 3029.127096] Lustre: *** cfs_fail_loc=1621, val=121*** [ 3029.133475] Lustre: Skipped 2599 previous similar messages [ 3033.243494] LustreError: 89667:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -2 [ 3033.252406] LustreError: 89667:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 2 previous similar messages [ 3033.512359] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3033.520607] Lustre: Skipped 1 previous similar message [ 3055.037735] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 20:18:42 (1787789922) [ 3056.634683] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23d needs >= 2 MDTs [ 3058.535728] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 20:18:46 (1787789926) [ 3060.509167] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_24 needs >= 2 MDTs [ 3063.119441] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 20:18:50 (1787789930) [ 3064.819628] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_25 only ldiskfs fixes dirent type [ 3066.624459] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 20:18:54 (1787789934) [ 3067.956447] Lustre: *** cfs_fail_loc=1624, val=0*** [ 3067.959654] Lustre: Skipped 1 previous similar message [ 3079.014217] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 20:19:07 (1787789947) [ 3080.242763] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_26b needs >= 2 MDTs [ 3081.989733] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 20:19:09 (1787789949) [ 3095.020208] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 20:19:22 (1787789962) [ 3096.535766] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_27b needs >= 2 MDTs [ 3098.802400] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 20:19:26 (1787789966) [ 3100.683548] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_28 needs >= 2 MDTs [ 3103.078554] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 20:19:30 (1787789970) [ 3104.493138] Lustre: *** cfs_fail_loc=1626, val=0*** [ 3104.502462] Lustre: Skipped 2 previous similar messages [ 3115.965502] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 20:19:43 (1787789983) [ 3138.360460] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 20:20:06 (1787790006) [ 3139.830436] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_29d ldiskfs only problem [ 3141.250521] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 20:20:09 (1787790009) [ 3142.761556] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_30 only ldiskfs has lost+found [ 3144.656231] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 20:20:12 (1787790012) [ 3146.521824] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31a needs >= 2 MDTs [ 3148.385135] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 20:20:16 (1787790016) [ 3150.137949] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31b needs >= 2 MDTs [ 3152.024435] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 20:20:19 (1787790019) [ 3154.009351] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31c needs >= 2 MDTs [ 3155.665885] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 20:20:23 (1787790023) [ 3157.346508] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31d needs >= 2 MDTs [ 3159.851785] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 20:20:27 (1787790027) [ 3163.034369] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31e needs >= 2 MDTs [ 3165.084837] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 20:20:32 (1787790032) [ 3168.121351] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31f needs >= 2 MDTs [ 3171.634956] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 20:20:38 (1787790038) [ 3174.124101] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31g needs >= 2 MDTs [ 3176.848658] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 20:20:44 (1787790044) [ 3179.648618] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_31h needs >= 2 MDTs [ 3181.420594] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 20:20:49 (1787790049) [ 3214.896438] LustreError: 93910:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 3217.011224] Lustre: Failing over lustre-OST0000 [ 3217.141249] Lustre: server umount lustre-OST0000 complete [ 3217.952097] LustreError: 93910:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 3217.966396] LustreError: 93910:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 3219.434428] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3219.446995] Lustre: Skipped 2 previous similar messages [ 3219.560743] LustreError: 93910:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 3230.233580] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3230.241844] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3231.917128] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3232.000083] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3232.001940] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3235.547858] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3243.615458] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 20:21:51 (1787790111) [ 3244.835775] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_32b needs >= 2 MDTs [ 3246.406540] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 20:21:54 (1787790114) [ 3257.851255] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 3266.423335] Lustre: 96288:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3266.431831] Lustre: 96288:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 3 previous similar messages [ 3283.687612] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3305.093400] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 20:22:53 (1787790173) [ 3306.479482] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 needs >= 2 MDTs [ 3308.292926] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 20:22:56 (1787790176) [ 3309.770387] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_35 needs >= 2 MDTs [ 3312.116791] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 20:22:59 (1787790179) [ 3313.737439] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 3315.812170] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 20:23:03 (1787790183) [ 3317.679621] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 3319.275310] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 20:23:07 (1787790187) [ 3320.724643] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 3322.367571] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 20:23:10 (1787790190) [ 3335.053799] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 20:23:22 (1787790202) [ 3350.194389] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 20:23:37 (1787790217) [ 3365.034182] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 20:23:53 (1787790233) [ 3366.402314] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_40a needs >= 2 MDTs [ 3368.428687] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 20:23:56 (1787790236) [ 3393.711843] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 20:24:21 (1787790261) [ 3395.381689] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_42 skip ZFS backend [ 3396.986640] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 20:24:24 (1787790264) [ 3398.475343] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_43 only ldiskfs uses iterate_dir [ 3400.080625] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 20:24:28 (1787790268) [ 3406.406255] Lustre: *** cfs_fail_loc=1600, val=3*** [ 3408.879700] Lustre: Failing over lustre-MDT0000 [ 3409.223725] Lustre: server umount lustre-MDT0000 complete [ 3417.053432] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3417.067375] LustreError: Skipped 1 previous similar message [ 3417.511496] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3417.515200] Lustre: Skipped 8 previous similar messages [ 3417.564627] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3417.648893] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3417.782795] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3417.816750] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3487 to 0x240000400:3521) [ 3417.824165] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3031 to 0x280000400:3073) [ 3421.885626] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3422.695336] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3425.768336] Lustre: 12931:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787790279/real 1787790279] req@ffff8d72cc870b40 x1874630747048576/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787790295 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3430.259407] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 20:24:58 (1787790298) [ 3430.886701] Lustre: 12929:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787790284/real 1787790284] req@ffff8d73c723b0c0 x1874630747048832/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787790300 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3430.913577] Lustre: 12929:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 3457.801630] Lustre: Failing over lustre-OST0000 [ 3457.948872] Lustre: server umount lustre-OST0000 complete [ 3458.545627] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 3458.546653] LustreError: 82279:0:(ldlm_lib.c:1190:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3458.566730] LustreError: 82279:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 4 previous similar messages [ 3481.730848] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3483.260578] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3483.798233] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3483.799823] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3483.816430] Lustre: Skipped 1 previous similar message [ 3488.295717] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3493.923860] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 3494.057547] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 3499.042803] Lustre: DEBUG MARKER: oleg105-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff955136650000.ost_server_uuid 50 [ 3500.787351] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff955136650000.ost_server_uuid in FULL state after 0 sec [ 3548.004120] Lustre: server umount lustre-MDT0000 complete [ 3551.298838] LustreError: 81461:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787790421 with bad export cookie 11364138024257350176 [ 3561.520504] Lustre: server umount lustre-OST0000 complete [ 3564.383200] Lustre: 12929:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787790418/real 1787790418] req@ffff8d73c72392c0 x1874630747097984/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787790434 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3564.416241] Lustre: 12929:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 3564.543374] Lustre: server umount lustre-OST0001 complete [ 3577.001603] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing unload_modules_local [ 3579.183277] Key type lgssc unregistered [ 3579.443136] LNet: 107599:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3579.450991] LNetError: 107599:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3579.468398] LNet: Removed LNI 192.168.201.105@tcp [ 3580.120452] Key type .llcrypt unregistered [ 3580.125343] Key type ._llcrypt unregistered [ 3593.857641] Key type ._llcrypt registered [ 3593.861430] Key type .llcrypt registered [ 3593.937925] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_hostid [ 3606.892942] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 3607.993835] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3608.299623] alg: No test for adler32 (adler32-zlib) [ 3609.452562] Lustre: Lustre: Build Version: 2.17.57_52_gc224de1 [ 3609.789929] LNet: Added LNI 192.168.201.105@tcp [8/256/0/180] [ 3611.600287] Key type lgssc registered [ 3612.810983] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3621.349993] vdc: vdc1 vdc9 [ 3630.384499] vde: vde1 vde9 [ 3639.377840] vdf: vdf1 vdf9 [ 3653.815264] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing load_modules_local [ 3661.868746] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3663.095456] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3663.404731] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3663.466366] Lustre: lustre-MDT0000: new disk, initializing [ 3663.799970] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3663.893632] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3668.219426] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3672.988884] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3678.738766] Lustre: lustre-OST0000: new disk, initializing [ 3678.741855] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3678.745249] Lustre: Skipped 1 previous similar message [ 3678.813357] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3684.660727] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3687.605376] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 3687.610707] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 3687.736151] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 3694.533779] Lustre: lustre-OST0001: new disk, initializing [ 3694.536296] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3694.612339] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3697.169822] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 3697.184742] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 3697.344879] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 3700.888522] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3712.126477] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3718.817445] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3722.588540] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 20:29:50 (1787790590) === [ 3724.392863] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 3510 sec ========= 20:29:52 (1787790592) [ 3725.958499] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 20:29:53 (1787790593) === [ 3729.426460] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 20:29:57 (1787790597) === [ 3733.284214] Lustre: server umount lustre-MDT0000 complete [ 3737.834454] LustreError: 111371:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787790607 with bad export cookie 677276601489721819 [ 3737.845697] LustreError: MGC192.168.201.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3747.367842] Lustre: server umount lustre-OST0000 complete [ 3761.475310] Lustre: server umount lustre-OST0001 complete [ 3775.512993] Lustre: DEBUG MARKER: oleg105-server.virtnet: executing unload_modules_local [ 3778.380528] Key type lgssc unregistered [ 3778.691633] LNet: 115372:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3778.704969] LNetError: 115372:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3778.723305] LNet: Removed LNI 192.168.201.105@tcp [ 3779.535201] Key type .llcrypt unregistered [ 3779.537801] Key type ._llcrypt unregistered