[ 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 486076115 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.001012] APIC: Switch to symmetric I/O mode setup [ 0.003121] x2apic enabled [ 0.004007] Switched APIC routing to physical x2apic. [ 0.005014] kvm-guest: setup PV IPIs [ 0.008000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008023] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009017] pid_max: default: 32768 minimum: 301 [ 0.010158] LSM: Security Framework initializing [ 0.011062] Yama: becoming mindful. [ 0.012040] SELinux: Initializing. [ 0.014012] *** VALIDATE selinux *** [ 0.022758] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027288] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028167] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030121] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031119] *** VALIDATE tmpfs *** [ 0.033475] *** VALIDATE proc *** [ 0.034236] *** VALIDATE cgroup *** [ 0.035011] *** VALIDATE cgroup2 *** [ 0.036264] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037154] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040031] Spectre V2 : User space: Vulnerable [ 0.041012] Speculative Store Bypass: Vulnerable [ 0.044006] debug: unmapping init [mem 0xffffffffa9859000-0xffffffffa9860fff] [ 0.046209] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.047759] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.048023] ... version: 2 [ 0.049011] ... bit width: 48 [ 0.050011] ... generic registers: 4 [ 0.051013] ... value mask: 0000ffffffffffff [ 0.052015] ... max period: 00007fffffffffff [ 0.053031] ... fixed-purpose events: 3 [ 0.054015] ... event mask: 000000070000000f [ 0.055316] rcu: Hierarchical SRCU implementation. [ 0.057560] smp: Bringing up secondary CPUs ... [ 0.058584] x86: Booting SMP configuration: [ 0.059031] .... node #0, CPUs: #1 #2 #3 [ 0.063084] smp: Brought up 1 node, 4 CPUs [ 0.065012] smpboot: Max logical packages: 1 [ 0.066009] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.140949] node 0 deferred pages initialised in 72ms [ 0.143199] devtmpfs: initialized [ 0.144385] x86/mm: Memory block size: 128MB [ 0.147674] gcov: version magic: 0x41383552 [ 0.150327] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.153099] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.155292] pinctrl core: initialized pinctrl subsystem [ 0.156151] [ 0.156562] ************************************************************* [ 0.159012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.160009] ** ** [ 0.162010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.164011] ** ** [ 0.166012] ** This means that this kernel is built to expose internal ** [ 0.168010] ** IOMMU data structures, which may compromise security on ** [ 0.169011] ** your system. ** [ 0.171011] ** ** [ 0.173012] ** If you see this message and you are not debugging the ** [ 0.175010] ** kernel, report this immediately to your vendor! ** [ 0.176011] ** ** [ 0.178014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.180010] ************************************************************* [ 0.182759] NET: Registered protocol family 16 [ 0.184471] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.186137] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.188060] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.191030] cpuidle: using governor menu [ 0.192589] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.194396] PCI: Using configuration type 1 for base access [ 0.196140] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.204000] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.205054] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.208088] cryptd: max_cpu_qlen set to 1000 [ 0.210205] ACPI: Added _OSI(Module Device) [ 0.211012] ACPI: Added _OSI(Processor Device) [ 0.213015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.214015] ACPI: Added _OSI(Processor Aggregator Device) [ 0.219241] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.225567] ACPI: Interpreter enabled [ 0.226057] ACPI: PM: (supports S0 S3 S4 S5) [ 0.228019] ACPI: Using IOAPIC for interrupt routing [ 0.229110] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.232596] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.244416] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.247045] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.249021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.251101] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.255343] acpiphp: Slot [2] registered [ 0.256395] acpiphp: Slot [5] registered [ 0.258100] acpiphp: Slot [6] registered [ 0.259101] acpiphp: Slot [7] registered [ 0.260085] acpiphp: Slot [8] registered [ 0.261083] acpiphp: Slot [9] registered [ 0.262114] acpiphp: Slot [10] registered [ 0.263071] acpiphp: Slot [3] registered [ 0.264138] acpiphp: Slot [4] registered [ 0.266125] acpiphp: Slot [11] registered [ 0.268109] acpiphp: Slot [12] registered [ 0.269085] acpiphp: Slot [13] registered [ 0.271175] acpiphp: Slot [14] registered [ 0.272098] acpiphp: Slot [15] registered [ 0.274148] acpiphp: Slot [16] registered [ 0.276103] acpiphp: Slot [17] registered [ 0.277087] acpiphp: Slot [18] registered [ 0.278110] acpiphp: Slot [19] registered [ 0.279075] acpiphp: Slot [20] registered [ 0.280092] acpiphp: Slot [21] registered [ 0.281089] acpiphp: Slot [22] registered [ 0.282085] acpiphp: Slot [23] registered [ 0.283082] acpiphp: Slot [24] registered [ 0.284100] acpiphp: Slot [25] registered [ 0.285074] acpiphp: Slot [26] registered [ 0.286116] acpiphp: Slot [27] registered [ 0.287069] acpiphp: Slot [28] registered [ 0.288075] acpiphp: Slot [29] registered [ 0.289075] acpiphp: Slot [30] registered [ 0.290099] acpiphp: Slot [31] registered [ 0.291057] PCI host bridge to bus 0000:00 [ 0.292011] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.294017] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.296019] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.297017] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.299022] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.302026] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.304196] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.305981] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.309581] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.320017] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.324061] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.327019] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.329018] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.332020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.335635] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.338977] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.342051] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.346694] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.351015] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.366016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.371013] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.375521] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.381017] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.387013] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.401017] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.408634] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.416016] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.423017] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.440024] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.450074] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.474019] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.501018] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.549020] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.572988] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.601026] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.614017] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.649024] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.671104] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.692022] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.702013] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.728023] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.739962] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.748019] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.754104] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.771017] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.780010] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.783436] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.786368] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.789230] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.793195] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.797106] iommu: Default domain type: Passthrough [ 0.799414] SCSI subsystem initialized [ 0.801149] ACPI: bus type USB registered [ 0.803122] usbcore: registered new interface driver usbfs [ 0.805068] usbcore: registered new interface driver hub [ 0.807081] usbcore: registered new device driver usb [ 0.809153] pps_core: LinuxPPS API ver. 1 registered [ 0.810009] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.813063] PTP clock support registered [ 0.815088] EDAC MC: Ver: 3.0.0 [ 0.817202] PCI: Using ACPI for IRQ routing [ 0.818868] NetLabel: Initializing [ 0.820009] NetLabel: domain hash size = 128 [ 0.820917] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.823087] NetLabel: unlabeled traffic allowed by default [ 0.825133] vgaarb: loaded [ 0.828211] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.829012] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.840304] clocksource: Switched to clocksource kvm-clock [ 0.951105] VFS: Disk quotas dquot_6.6.0 [ 0.952238] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.954667] *** VALIDATE ramfs *** [ 0.955960] *** VALIDATE hugetlbfs *** [ 0.957564] pnp: PnP ACPI init [ 0.959495] pnp: PnP ACPI: found 6 devices [ 0.977079] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.979568] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.981278] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.982855] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.984689] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.986477] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.988624] NET: Registered protocol family 2 [ 0.990707] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.994647] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.996857] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.000667] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.002828] TCP: Hash tables configured (established 65536 bind 65536) [ 1.004589] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.006417] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.008136] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.009879] NET: Registered protocol family 1 [ 1.011487] RPC: Registered named UNIX socket transport module. [ 1.012729] RPC: Registered udp transport module. [ 1.013728] RPC: Registered tcp transport module. [ 1.014735] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.017133] NET: Registered protocol family 44 [ 1.018520] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.020231] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.021742] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.024510] PCI: CLS 0 bytes, default 64 [ 1.026469] Unpacking initramfs... [ 2.402910] debug: unmapping init [mem 0xffff8ed5fcc54000-0xffff8ed5fffbffff] [ 2.407062] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.409346] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.412336] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.928667] Initialise system trusted keyrings [ 2.930465] Key type blacklist registered [ 2.931802] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.940385] zbud: loaded [ 2.943535] *** VALIDATE nfs *** [ 2.945096] *** VALIDATE nfs4 *** [ 2.946875] pstore: using deflate compression [ 2.950807] Platform Keyring initialized [ 3.047579] NET: Registered protocol family 38 [ 3.049249] Key type asymmetric registered [ 3.050723] Asymmetric key parser 'x509' registered [ 3.052395] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.055299] io scheduler mq-deadline registered [ 3.057354] io scheduler kyber registered [ 3.059172] io scheduler bfq registered [ 3.062728] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.064873] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.066981] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.070145] ACPI: Power Button [PWRF] [ 3.075498] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.082131] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.093957] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.107409] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.132842] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.162884] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.192308] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.197144] Non-volatile memory driver v1.3 [ 3.198717] Linux agpgart interface v0.103 [ 3.227548] virtio_blk virtio1: [vda] 147224 512-byte logical blocks (75.4 MB/71.9 MiB) [ 3.230417] vda: detected capacity change from 0 to 75378688 [ 3.252665] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.256043] vdb: detected capacity change from 0 to 1073741824 [ 3.280025] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.285240] vdc: detected capacity change from 0 to 2621440000 [ 3.311851] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.314828] vdd: detected capacity change from 0 to 2621440000 [ 3.338158] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.341447] vde: detected capacity change from 0 to 4294967296 [ 3.358861] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.361496] vdf: detected capacity change from 0 to 4294967296 [ 3.370690] libphy: Fixed MDIO Bus: probed [ 3.380056] usbcore: registered new interface driver usbserial_generic [ 3.381921] usbserial: USB Serial support registered for generic [ 3.383803] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.387788] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.389215] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.391176] mousedev: PS/2 mouse device common for all mice [ 3.393237] rtc_cmos 00:05: RTC can wake from S4 [ 3.396315] rtc_cmos 00:05: registered as rtc0 [ 3.397974] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.400952] intel_pstate: CPU model not supported [ 3.401540] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.408100] hid: raw HID events driver (C) Jiri Kosina [ 3.410531] usbcore: registered new interface driver usbhid [ 3.411121] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.413063] usbhid: USB HID core driver [ 3.417915] drop_monitor: Initializing network drop monitor service [ 3.420348] Initializing XFRM netlink socket [ 3.420466] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.421966] NET: Registered protocol family 10 [ 3.427095] Segment Routing with IPv6 [ 3.427919] NET: Registered protocol family 17 [ 3.429414] mpls_gso: MPLS GSO support [ 3.434375] RAS: Correctable Errors collector initialized. [ 3.436297] AVX version of gcm_enc/dec engaged. [ 3.437781] AES CTR mode by8 optimization enabled [ 3.508060] sched_clock: Marking stable (3508031735, 0)->(4422982631, -914950896) [ 3.510861] registered taskstats version 1 [ 3.512529] Loading compiled-in X.509 certificates [ 3.514965] zswap: loaded using pool lzo/zbud [ 3.538190] Key type big_key registered [ 3.549877] Key type encrypted registered [ 3.551730] ima: No TPM chip found, activating TPM-bypass! [ 3.553492] ima: Allocated hash algorithm: sha1 [ 3.555184] ima: No architecture policies found [ 3.556825] evm: Initialising EVM extended attributes: [ 3.558893] evm: security.selinux [ 3.560291] evm: security.ima [ 3.561475] evm: security.capability [ 3.564147] evm: HMAC attrs: 0x1 [ 3.566692] rtc_cmos 00:05: setting system clock to 2026-09-11 11:16:45 UTC (1789125405) [ 3.573271] debug: unmapping init [mem 0xffffffffaa803000-0xffffffffaa9fffff] [ 3.576934] debug: unmapping init [mem 0xffffffffa9582000-0xffffffffa9858fff] [ 3.586048] Write protecting the kernel read-only data: 28672k [ 3.588674] debug: unmapping init [mem 0xffffffffa7c03000-0xffffffffa7dfffff] [ 3.592071] debug: unmapping init [mem 0xffffffffa8514000-0xffffffffa85fffff] [ 3.626123] 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.634899] systemd[1]: Detected virtualization kvm. [ 3.637775] systemd[1]: Detected architecture x86-64. [ 3.640333] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.666886] systemd[1]: No hostname configured. [ 3.668979] systemd[1]: Set hostname to . [ 3.671240] random: systemd: uninitialized urandom read (16 bytes read) [ 3.673722] systemd[1]: Initializing machine ID from random generator. [ 3.829293] random: systemd: uninitialized urandom read (16 bytes read) [ 3.832475] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 3.837711] random: systemd: uninitialized urandom read (16 bytes read) [ 3.840636] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 3.846224] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Swap. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... Starting Apply Kernel Variables... [ OK ] Reached target Sockets. [ OK ] Started Memstrack Anylazing Service. Starting Create Volatile Files and Directories... Starting Create list of required st…ce nodes for the current kernel... Starting Journal Service... [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Slices. [ OK ] Reached target Timers. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.505216] device-mapper: uevent: version 1.0.3 [ 4.506945] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.268828] virtio_net virtio0 ens2: renamed from eth0 [ 5.360122] random: fast init done [ 5.378928] scsi host0: ata_piix [ 5.389693] scsi host1: ata_piix [ 5.391741] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.394363] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.790612] dracut-initqueue[586]: RTNETLINK answers: File exists [ 10.070358] random: crng init done [ 10.071813] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 10.561236] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ 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.624213] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.873654] SELinux: Disabled at runtime. [ 11.933670] 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.942471] systemd[1]: Detected virtualization kvm. [ 11.944330] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.761176] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.773283] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.780878] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.785350] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.801206] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.815386] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.837463] systemd[1]: Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting POSIX Message Queue File System... [ OK ] Listening on Process Core Dump Socket. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice system-getty.slice. [ OK ] Created slice User and Session Slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. Mounting Kernel Debug File System... Starting Apply Kernel Variables... Mounting Huge Pages File System... [ OK ] Reached target rpc_pipefs.target. Activating swap /dev/disk/by-label/SWAP... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ 13.356290] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Remount Root and Kernel File Systems... [ OK ] Stopped target Initrd Root File System. [ OK ] Reached target Slices. [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [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... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 14.582489] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 15.780535] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 15.827730] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 16.367426] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 16.427987] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit) [** ] A start job is running for Configur…-only root support (8s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit)[ 21.857893] Key type dns_resolver registered [ *** ] A start job is running for Configur…-only root support (9s / no limit)[ 22.680354] NFS: Registering the id_resolver key type [ 22.685964] Key type id_resolver registered [ 22.689896] Key type id_legacy registered [ *** ] A start job is running for Configur…only root support (10s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Mark the need to relabel after reboot. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started irqbalance daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg248-server login: [ 63.124447] spl: loading out-of-tree module taints kernel. [ 70.412507] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 83.719036] Key type ._llcrypt registered [ 83.720373] Key type .llcrypt registered [ 83.823957] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_hostid [ 104.159311] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 105.949812] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 105.974295] alg: No test for adler32 (adler32-zlib) [ 107.492361] Lustre: Lustre: Build Version: 2.17.57_137_gfce00d1 [ 108.668174] LNet: Added LNI 192.168.202.148@tcp [8/256/0/180] [ 110.471177] Key type lgssc registered [ 112.506338] Lustre: Echo OBD driver; http://www.lustre.org/ [ 121.340232] hrtimer: interrupt took 3271913 ns [ 123.464850] vdc: vdc1 vdc9 [ 134.309877] vde: vde1 vde9 [ 144.753223] vdf: vdf1 vdf9 [ 162.739541] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 173.250923] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 174.682635] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 175.083890] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 175.198803] Lustre: lustre-MDT0000: new disk, initializing [ 175.675355] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 175.769636] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 180.285832] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 185.517239] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 192.204791] Lustre: lustre-OST0000: new disk, initializing [ 192.209176] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 192.213504] Lustre: Skipped 1 previous similar message [ 192.309779] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 193.432373] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 193.440746] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 193.594773] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 200.375925] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 212.610091] Lustre: lustre-OST0001: new disk, initializing [ 212.613403] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 212.732943] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 218.327405] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 218.335417] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 218.534996] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 220.107254] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 234.166570] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 241.523371] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 247.774786] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing check_logdir /tmp/testlogs/ [ 252.612701] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing yml_node [ 258.104812] Lustre: DEBUG MARKER: Client: 2.17.57.137 [ 260.704874] Lustre: DEBUG MARKER: MDS: 2.17.57.137 [ 263.347547] Lustre: DEBUG MARKER: OSS: 2.17.57.137 [ 264.870655] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Fri Sep 11 07:21:04 EDT 2026 [ 282.753263] Lustre: DEBUG MARKER: excepting tests: [ 293.633683] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 305.122087] 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 [ 305.125367] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 305.140314] Lustre: Skipped 1 previous similar message [ 305.156877] Lustre: Skipped 1 previous similar message [ 308.177265] Lustre: server umount lustre-MDT0000 complete [ 312.829683] LustreError: 5829:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789125714 with bad export cookie 7089264505230598147 [ 312.833926] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 312.841634] LustreError: 5829:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 313.153596] Lustre: server umount lustre-OST0000 complete [ 317.890610] Lustre: server umount lustre-OST0001 complete [ 329.840553] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing unload_modules_local [ 332.964714] Key type lgssc unregistered [ 333.277847] LNet: 11679:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 333.289916] LNetError: 11679:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 334.311786] LNet: Removed LNI 192.168.202.148@tcp [ 335.165187] Key type .llcrypt unregistered [ 335.167466] Key type ._llcrypt unregistered [ 351.766244] Key type ._llcrypt registered [ 351.770479] Key type .llcrypt registered [ 351.928099] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_hostid [ 366.402992] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 368.825274] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 368.863301] alg: No test for adler32 (adler32-zlib) [ 370.204984] Lustre: Lustre: Build Version: 2.17.57_137_gfce00d1 [ 370.545309] LNet: Added LNI 192.168.202.148@tcp [8/256/0/180] [ 372.313380] Key type lgssc registered [ 374.189138] Lustre: Echo OBD driver; http://www.lustre.org/ [ 383.202061] vdc: vdc1 vdc9 [ 392.356727] vde: vde1 vde9 [ 403.036746] vdf: vdf1 vdf9 [ 420.687968] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 431.951739] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 433.635676] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 433.765491] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 433.862293] Lustre: lustre-MDT0000: new disk, initializing [ 434.400222] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 434.513739] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 439.686388] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 444.463620] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 451.648240] Lustre: lustre-OST0000: new disk, initializing [ 451.651388] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 451.655154] Lustre: Skipped 1 previous similar message [ 451.731896] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 458.017605] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 458.024749] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 458.197801] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 458.453899] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 469.369296] Lustre: lustre-OST0001: new disk, initializing [ 469.374072] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 469.485631] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 476.348729] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 479.490448] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 479.501608] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 479.718706] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 488.228887] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 497.604864] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 504.387299] Lustre: Setting parameter lustre.lod.lustre-MDT0000-mdtlov.enable_compr_rotational=1 in log params [ 510.120576] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 07:25:10 (1789125910) === [ 512.879960] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 07:25:13 (1789125913) [ 526.480041] Lustre: Failing over lustre-MDT0000 [ 526.993717] Lustre: server umount lustre-MDT0000 complete [ 537.396900] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 537.710899] 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 [ 537.721020] Lustre: Skipped 1 previous similar message [ 537.844644] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 537.929816] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:42 to 0x240000400:65) [ 537.933732] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 542.117274] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 543.216802] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 546.272934] Lustre: 12954:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789125932/real 1789125932] req@ffff8ed5489bcb40 x1876034345565312/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789125948 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 546.911412] Lustre: 12955:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789125932/real 1789125932] req@ffff8ed5489bd680 x1876034345565440/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789125948 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 551.391234] Lustre: 12953:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789125937/real 1789125937] req@ffff8ed5489bf840 x1876034345565824/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789125953 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 552.532473] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 07:25:52 (1789125952) [ 567.576396] Lustre: Failing over lustre-MDT0000 [ 567.923759] Lustre: server umount lustre-MDT0000 complete [ 577.404104] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 577.753038] 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 [ 577.959881] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 578.065664] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 578.068591] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:106 to 0x240000400:129) [ 583.142547] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 583.149289] Lustre: Skipped 1 previous similar message [ 583.189414] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 584.162530] Lustre: 12953:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789125970/real 1789125970] req@ffff8ed675dda1c0 x1876034345609216/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789125986 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 584.202247] Lustre: 12953:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 587.373743] Lustre: *** cfs_fail_loc=193, val=0*** [ 589.279319] Lustre: 12956:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789125975/real 1789125975] req@ffff8ed675dd92c0 x1876034345609472/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789125991 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 591.686608] Lustre: Failing over lustre-MDT0000 [ 592.022630] Lustre: server umount lustre-MDT0000 complete [ 600.027868] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 600.409535] 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 [ 600.427110] Lustre: Skipped 2 previous similar messages [ 600.559469] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 600.650067] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:161) [ 600.660076] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:106 to 0x240000400:161) [ 605.049196] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 605.670927] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 605.675630] Lustre: Skipped 1 previous similar message [ 609.567159] Lustre: 12953:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789125995/real 1789125995] req@ffff8ed67cfe21c0 x1876034345630336/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789126011 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 609.582527] Lustre: 12953:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 614.526793] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 07:26:54 (1789126014) [ 627.574931] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 636.852753] Lustre: 23467:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 657.340348] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 661.195675] Lustre: 24413:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 668.085252] Lustre: *** cfs_fail_loc=198, val=0*** [ 677.422103] Lustre: Failing over lustre-MDT0000 [ 678.034124] Lustre: server umount lustre-MDT0000 complete [ 686.357276] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 686.793725] 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 [ 686.811966] Lustre: Skipped 1 previous similar message [ 686.961867] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 687.123063] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:202 to 0x280000400:225) [ 687.130526] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:202 to 0x240000400:225) [ 691.331552] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 692.207587] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 692.217083] Lustre: Skipped 1 previous similar message [ 698.352330] Lustre: 12956:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789126084/real 1789126084] req@ffff8ed6607cf480 x1876034345693312/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789126100 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 698.404217] Lustre: 12956:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 700.811528] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 07:28:21 (1789126101) [ 702.501325] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_1c ldiskfs special test [ 704.325846] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 07:28:24 (1789126104) [ 705.725284] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_2 ldiskfs special test [ 707.468269] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 07:28:27 (1789126107) [ 714.115791] Lustre: *** cfs_fail_loc=193, val=0*** [ 724.340276] Lustre: Failing over lustre-MDT0000 [ 725.017265] Lustre: server umount lustre-MDT0000 complete [ 733.914819] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 734.135239] 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 [ 734.361547] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 734.467098] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:265 to 0x280000400:289) [ 734.470510] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:266 to 0x240000400:289) [ 739.088959] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 739.319656] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 739.338351] Lustre: Skipped 1 previous similar message [ 743.391225] Lustre: 12954:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789126129/real 1789126129] req@ffff8ed545f74b40 x1876034345746176/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789126145 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 743.431975] Lustre: 12954:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 743.611040] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002341:0x4e:0x0]/0x340): rc = 0 [ 743.625154] LustreError: 27277:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 762.403483] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 07:29:21 (1789126161) [ 764.163543] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4b ldiskfs special test [ 766.229855] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 07:29:25 (1789126165) [ 767.509548] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4c ldiskfs special test [ 769.627694] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 07:29:29 (1789126169) [ 771.638509] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4d ldiskfs only test [ 774.352386] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 07:29:33 (1789126173) [ 776.098523] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4e ldiskfs only test [ 778.498363] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 07:29:38 (1789126178) [ 795.657881] 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 [ 795.663372] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 795.698551] Lustre: Skipped 2 previous similar messages [ 795.733912] Lustre: Skipped 1 previous similar message [ 800.739126] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 800.759814] Lustre: Skipped 1 previous similar message [ 801.861092] Lustre: server umount lustre-MDT0000 complete [ 806.358316] LustreError: 17257:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789126208 with bad export cookie 17279616917200608198 [ 806.371237] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 806.378361] LustreError: 17257:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 812.583465] Lustre: server umount lustre-OST0000 complete [ 823.647266] Lustre: server umount lustre-OST0001 complete [ 831.847214] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_hostid [ 841.314886] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 851.938662] vdc: vdc1 vdc9 [ 861.422351] vde: vde1 vde9 [ 871.440404] vdf: vdf1 vdf9 [ 871.488244] vdf: vdf1 vdf9 [ 871.525629] vdf: vdf1 vdf9 [ 889.570348] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 901.271789] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 901.321902] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 901.374891] Lustre: lustre-MDT0000: new disk, initializing [ 901.722096] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 901.761065] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 906.225231] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 911.180296] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 918.466343] Lustre: lustre-OST0000: new disk, initializing [ 918.468508] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 918.472046] Lustre: Skipped 1 previous similar message [ 920.371397] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 920.381590] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 920.555125] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 925.905023] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 937.991633] Lustre: lustre-OST0001: new disk, initializing [ 937.996908] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 939.602485] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 939.612117] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 939.854585] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 945.566913] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 954.342155] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 957.493483] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 963.808248] Lustre: *** cfs_fail_loc=193, val=0*** [ 963.812300] Lustre: Skipped 3 previous similar messages [ 973.352349] Lustre: Failing over lustre-MDT0000 [ 973.585265] Lustre: server umount lustre-MDT0000 complete [ 981.844471] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 982.196722] 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 [ 982.669989] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:41 to 0x240000400:65) [ 982.674816] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 987.618868] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 987.630799] Lustre: Skipped 1 previous similar message [ 988.081078] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 991.712403] Lustre: 12955:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789126377/real 1789126377] req@ffff8ed54b5ea580 x1876034345819776/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789126393 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 991.748565] Lustre: 12955:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 994.764952] Lustre: *** cfs_fail_loc=190, val=3*** [ 994.765966] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000401:0x4e:0x0]/0x164): rc = 0 [ 994.788924] LustreError: 35433:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 994.808756] LustreError: 35433:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 997.862793] Lustre: *** cfs_fail_loc=190, val=3*** [ 997.874354] Lustre: Skipped 1 previous similar message [ 1000.928763] Lustre: *** cfs_fail_loc=191, val=3*** [ 1004.273338] Lustre: Failing over lustre-MDT0000 [ 1004.754686] Lustre: server umount lustre-MDT0000 complete [ 1014.265361] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1014.611218] 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 [ 1014.633216] Lustre: Skipped 1 previous similar message [ 1014.903614] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 1014.947462] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:41 to 0x240000400:97) [ 1019.902072] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1019.912806] Lustre: Skipped 1 previous similar message [ 1020.787435] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1026.022788] Lustre: Failing over lustre-MDT0000 [ 1026.452858] Lustre: server umount lustre-MDT0000 complete [ 1035.250785] Lustre: *** cfs_fail_loc=190, val=3*** [ 1035.763316] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1035.765653] Lustre: Skipped 4 previous similar messages [ 1035.949211] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 1035.972933] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:41 to 0x240000400:129) [ 1040.817693] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1041.312584] Lustre: *** cfs_fail_loc=190, val=3*** [ 1041.324768] Lustre: Skipped 1 previous similar message [ 1049.428180] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000401:0x45:0x0]/0x15e): rc = 0 [ 1049.432877] LustreError: 37883:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 1056.979532] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 07:34:17 (1789126457) [ 1066.112694] Lustre: *** cfs_fail_loc=193, val=0*** [ 1066.115581] Lustre: Skipped 3 previous similar messages [ 1075.656657] Lustre: Failing over lustre-MDT0000 [ 1076.045816] Lustre: server umount lustre-MDT0000 complete [ 1085.962507] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1085.998392] LustreError: Skipped 1 previous similar message [ 1086.395460] 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 [ 1086.438561] Lustre: Skipped 3 previous similar messages [ 1086.682802] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 1086.685721] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:169 to 0x240000400:193) [ 1091.566391] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1091.581386] Lustre: Skipped 3 previous similar messages [ 1092.225101] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1099.433904] Lustre: *** cfs_fail_loc=190, val=2*** [ 1099.434909] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b71:0x4e:0x0]/0x428): rc = 0 [ 1099.437183] Lustre: Skipped 2 previous similar messages [ 1099.512137] LustreError: 39464:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 1110.032738] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b71:0x45:0x0]/0x3b2): rc = 0 [ 1110.047100] LustreError: 39662:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 1116.127163] Lustre: *** cfs_fail_loc=191, val=3*** [ 1116.128546] Lustre: Skipped 8 previous similar messages [ 1121.446876] Lustre: Failing over lustre-MDT0000 [ 1121.833682] Lustre: server umount lustre-MDT0000 complete [ 1134.121809] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 1134.125068] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:169 to 0x240000400:225) [ 1138.335105] Lustre: 12953:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789126524/real 1789126524] req@ffff8ed6765a5680 x1876034345905408/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789126540 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1138.371735] Lustre: 12953:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 14 previous similar messages [ 1138.630061] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1155.506611] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 07:35:55 (1789126555) [ 1169.887647] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 1179.598375] Lustre: 42221:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1198.367564] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1201.689359] Lustre: 43166:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1215.962507] Lustre: *** cfs_fail_loc=193, val=0*** [ 1215.969769] Lustre: Skipped 3 previous similar messages [ 1226.707284] Lustre: Failing over lustre-MDT0000 [ 1226.988239] Lustre: server umount lustre-MDT0000 complete [ 1236.711735] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1236.720509] LustreError: Skipped 1 previous similar message [ 1237.160257] 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 [ 1237.170219] Lustre: Skipped 3 previous similar messages [ 1237.562832] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:265 to 0x240000400:289) [ 1237.563110] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 1241.030148] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1242.600107] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1242.611037] Lustre: Skipped 3 previous similar messages [ 1247.180846] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b11:0x4e:0x0]/0x326): rc = 0 [ 1247.183538] Lustre: *** cfs_fail_loc=190, val=3*** [ 1247.198449] Lustre: Skipped 4 previous similar messages [ 1247.214351] LustreError: 44615:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 1266.077374] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 07:37:45 (1789126665) [ 1289.038789] Lustre: *** cfs_fail_loc=193, val=0*** [ 1289.049362] Lustre: Skipped 3 previous similar messages [ 1300.654434] Lustre: Failing over lustre-MDT0000 [ 1300.984540] Lustre: server umount lustre-MDT0000 complete [ 1310.441826] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1310.445317] Lustre: Skipped 3 previous similar messages [ 1310.531466] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 1310.533890] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:329 to 0x240000400:353) [ 1314.751624] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1319.898846] Lustre: *** cfs_fail_loc=190, val=1*** [ 1319.901549] Lustre: Skipped 2 previous similar messages [ 1328.869834] LustreError: 46801:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 1328.898434] LustreError: 46801:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 1342.440602] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 07:39:01 (1789126741) [ 1344.858531] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_9 test scrub speed only on ldiskfs [ 1346.939783] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 07:39:06 (1789126746) [ 1362.425522] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 1373.451314] Lustre: 48259:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1393.198658] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1397.308461] Lustre: 49203:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1405.976411] Lustre: *** cfs_fail_loc=193, val=0*** [ 1405.982020] Lustre: Skipped 3 previous similar messages [ 1416.957348] Lustre: Failing over lustre-MDT0000 [ 1417.241594] Lustre: server umount lustre-MDT0000 complete [ 1426.585165] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 1426.593171] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:393 to 0x240000400:417) [ 1431.557069] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1431.575708] Lustre: Skipped 3 previous similar messages [ 1431.887395] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1433.634553] Lustre: 12955:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789126819/real 1789126819] req@ffff8ed65026f0c0 x1876034346095360/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789126835 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1433.669530] Lustre: 12955:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 13 previous similar messages [ 1437.581629] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200003ab1:0x4e:0x0]/0x1ec): rc = 0 [ 1437.589444] LustreError: 50488:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 1437.595029] LustreError: 50488:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 1442.450560] Lustre: Failing over lustre-MDT0000 [ 1442.727548] Lustre: server umount lustre-MDT0000 complete [ 1453.126419] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:449) [ 1453.128724] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:393 to 0x240000400:449) [ 1458.187511] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1463.074131] Lustre: Failing over lustre-MDT0000 [ 1463.273368] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1463.431421] Lustre: server umount lustre-MDT0000 complete [ 1472.006491] Lustre: *** cfs_fail_loc=190, val=1*** [ 1472.016627] Lustre: Skipped 12 previous similar messages [ 1472.946526] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:481) [ 1472.946773] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:393 to 0x240000400:481) [ 1478.238848] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1493.035274] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 07:41:33 (1789126893) [ 1494.678805] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_11 ldiskfs special test [ 1496.936516] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 07:41:36 (1789126896) [ 1509.765780] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 1519.496708] Lustre: 53911:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1539.362536] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1546.849609] Lustre: *** cfs_fail_loc=195, val=0*** [ 1546.852813] Lustre: Skipped 3 previous similar messages [ 1551.720340] Lustre: Failing over lustre-OST0000 [ 1551.838562] Lustre: server umount lustre-OST0000 complete [ 1554.417852] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 1554.433380] 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 [ 1554.457240] Lustre: Skipped 9 previous similar messages [ 1560.544971] LustreError: 32437:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1560.567499] LustreError: 32437:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 3 previous similar messages [ 1562.407199] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1563.745904] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1563.841774] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1569.322494] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1572.438562] LustreError: 34097:0:(osd_object.c:462:osd_check_lma()) lustre-OST0000: FID-in-LMA [0x240000400:0x204:0x0] does not match the object self-fid [0x240000400:0x203:0x0]: rc = -78 [ 1572.448252] LustreError: 34097:0:(osd_object.c:462:osd_check_lma()) Skipped 1 previous similar message [ 1572.613212] LustreError: 45174:0:(osd_object.c:590:osd_object_init()) lustre-OST0000: lookup [0x240000400:0x208:0x0]/0x400 failed: rc = -2 [ 1749.775076] LustreError: 43244:0:(osd_object.c:590:osd_object_init()) lustre-OST0000: lookup [0x240000400:0x208:0x0]/0x400 failed: rc = -2 [ 1752.127785] LustreError: 56191:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-OST0000: can't get bonus, rc = -2 [ 1752.151286] LustreError: 56191:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 1762.648255] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 07:46:02 (1789127162) [ 1766.572129] Lustre: *** cfs_fail_loc=196, val=0*** [ 1766.574635] Lustre: Skipped 63 previous similar messages [ 1773.232787] Lustre: Failing over lustre-OST0000 [ 1773.402130] Lustre: server umount lustre-OST0000 complete [ 1774.048920] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 1774.056738] LustreError: 38190:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1777.636289] LustreError: 49226:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1782.647537] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1784.316408] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1784.603912] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1784.607819] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1784.632140] Lustre: Skipped 6 previous similar messages [ 1789.714267] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1979.643202] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 07:49:39 (1789127379) [ 1980.880050] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_14 ldiskfs special test [ 1982.288738] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 07:49:42 (1789127382) [ 1997.794669] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1997.802836] Lustre: Skipped 2 previous similar messages [ 1999.162555] Lustre: server umount lustre-MDT0000 complete [ 2003.682655] LustreError: 45175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789127405 with bad export cookie 17279616917200735570 [ 2003.690384] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2003.691076] LustreError: 45175:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2003.713198] LustreError: Skipped 4 previous similar messages [ 2009.854777] Lustre: server umount lustre-OST0000 complete [ 2014.268749] Lustre: server umount lustre-OST0001 complete [ 2022.041588] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_hostid [ 2030.727647] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 2039.564050] vdc: vdc1 vdc9 [ 2049.196205] vde: vde1 vde9 [ 2059.278301] vdf: vdf1 vdf9 [ 2075.949658] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 2086.304329] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2086.380139] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2086.440331] Lustre: lustre-MDT0000: new disk, initializing [ 2086.736166] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2086.739677] Lustre: Skipped 5 previous similar messages [ 2086.783808] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2091.710827] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2096.770126] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2103.444256] Lustre: lustre-OST0000: new disk, initializing [ 2103.450253] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2103.456538] Lustre: Skipped 1 previous similar message [ 2105.623772] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 2105.636609] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2105.792480] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2110.410986] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2121.678781] Lustre: lustre-OST0001: new disk, initializing [ 2121.682318] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2123.393234] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 2123.405971] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 2123.482388] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 2129.366408] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2138.840452] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2142.538887] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2148.096926] Lustre: *** cfs_fail_loc=193, val=0*** [ 2148.100127] Lustre: Skipped 63 previous similar messages [ 2157.844342] Lustre: Failing over lustre-MDT0000 [ 2158.100346] Lustre: server umount lustre-MDT0000 complete [ 2167.083831] 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 [ 2167.114075] Lustre: Skipped 4 previous similar messages [ 2167.512073] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:42 to 0x240000400:65) [ 2167.512954] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 2172.802957] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2175.459828] Lustre: 12956:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789127561/real 1789127561] req@ffff8ed677363840 x1876034346324736/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789127577 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2175.481621] Lustre: 12956:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 2176.079943] LustreError: 65459:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 2176.092750] LustreError: 65459:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 2201.083619] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 07:53:21 (1789127601) [ 2215.592280] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 2225.659796] Lustre: 67503:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2225.665660] Lustre: 67503:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2248.227466] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2252.899724] Lustre: 68448:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2270.230190] Lustre: Failing over lustre-MDT0000 [ 2270.299660] Lustre: *** cfs_fail_loc=199, val=0*** [ 2270.306823] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 2270.321606] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x3:0x0]: rc = 0 [ 2270.335449] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 2270.349882] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 2270.362178] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 2270.371846] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 2270.387169] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 2270.395256] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xf:0x0]: rc = 0 [ 2270.405162] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x11:0x0]: rc = 0 [ 2270.411241] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x36:0x0]: rc = 0 [ 2270.418446] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 2270.426110] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 2270.433378] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 2270.443800] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 2270.454606] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 2270.464147] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 2270.475120] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 2270.493372] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 2270.504057] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 2270.516670] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 2270.528405] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 2270.540850] Lustre: 68764:0:(scrub.c:1092:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 2270.936385] Lustre: server umount lustre-MDT0000 complete [ 2280.846497] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 2280.862413] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x36:0x0]: rc = 0 [ 2280.875532] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x3:0x0]: rc = 0 [ 2280.885976] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xc:0x0]: rc = 0 [ 2280.903100] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 2280.924963] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xd:0x0]: rc = 0 [ 2280.942436] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 2280.963138] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 2280.969895] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xb:0x0]: rc = 0 [ 2280.997279] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xe:0x0]: rc = 0 [ 2281.018572] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 2281.032883] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0xa:0x0]: rc = 0 [ 2281.040072] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 2281.048467] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 2281.062289] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xf:0x0]: rc = 0 [ 2281.087578] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 2281.103395] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 2281.132174] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 2281.164046] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 2281.189920] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 2281.218042] Lustre: 69281:0:(osd_scrub.c:952:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 2282.449439] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:105 to 0x240000400:129) [ 2282.449460] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 2288.131610] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2298.980078] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 07:54:58 (1789127698) [ 2300.992851] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_17a ldiskfs only test [ 2303.019605] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 07:55:02 (1789127702) [ 2304.992818] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_17b ldiskfs only test [ 2306.974453] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 07:55:06 (1789127706) [ 2325.476499] Lustre: Failing over lustre-MDT0000 [ 2325.841746] Lustre: server umount lustre-MDT0000 complete [ 2335.713625] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 2335.726657] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:170 to 0x240000400:193) [ 2340.854483] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2340.857987] Lustre: Skipped 4 previous similar messages [ 2341.238362] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2347.719739] Lustre: Failing over lustre-MDT0000 [ 2348.158343] Lustre: server umount lustre-MDT0000 complete [ 2356.568612] Lustre: lustre-MDT0000: reset Object Index mappings [ 2358.032252] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:170 to 0x240000400:225) [ 2358.037277] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 2363.175791] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2374.922458] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 07:56:14 (1789127774) [ 2383.183852] Lustre: server umount lustre-MDT0000 complete [ 2386.876015] LustreError: 61658:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789127788 with bad export cookie 17279616917200794566 [ 2396.216474] Lustre: server umount lustre-OST0000 complete [ 2400.660141] Lustre: server umount lustre-OST0001 complete [ 2442.143827] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2447.263339] LustreError: 74146:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.148@tcp: failed processing log, type 4: rc = -110 [ 2479.927767] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2485.526405] Lustre: Failing over lustre-OST0000 [ 2485.758261] Lustre: server umount lustre-OST0000 complete [ 2523.039861] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2528.159391] LustreError: 76040:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.148@tcp: failed processing log, type 4: rc = -110 [ 2559.779766] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2567.492990] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 07:59:27 (1789127967) [ 2569.165867] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_20 ldiskfs only test [ 2571.639263] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 07:59:31 (1789127971) [ 2573.340372] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_21 needs >= 2 MDTs [ 2575.257944] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 07:59:35 (1789127975) [ 2580.652348] Lustre: server umount lustre-OST0000 complete [ 2606.756091] LustreError: 78599:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -2 [ 2606.760993] LustreError: 78599:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 9 previous similar messages [ 2611.853397] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2618.122292] Lustre: Failing over lustre-MDT0000 [ 2618.406923] Lustre: server umount lustre-MDT0000 complete [ 2648.905842] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2656.306481] Lustre: DEBUG MARKER: === sanity-scrub: start setup 08:00:56 (1789128056) === [ 2659.549628] Lustre: server umount lustre-MDT0000 complete [ 2675.836335] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_hostid [ 2685.097232] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 2695.637507] vdc: vdc1 vdc9 [ 2706.119152] vde: vde1 vde9 [ 2706.176978] vde: vde1 vde9 [ 2706.206276] vde: vde1 vde9 [ 2716.123876] vdf: vdf1 vdf9 [ 2733.394640] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing load_modules_local [ 2743.304195] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2743.530938] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2743.590888] Lustre: lustre-MDT0000: new disk, initializing [ 2743.937531] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2743.943361] Lustre: Skipped 10 previous similar messages [ 2743.995445] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2748.575618] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2758.936383] Lustre: lustre-OST0000: new disk, initializing [ 2758.941569] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2758.948617] Lustre: Skipped 1 previous similar message [ 2761.083429] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 2761.090507] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2761.396748] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2765.651912] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2775.718774] Lustre: lustre-OST0001: new disk, initializing [ 2775.721899] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2777.700662] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 2777.703804] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 2777.883383] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 2781.639400] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2791.289496] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2795.047875] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2795.052682] Lustre: Skipped 1 previous similar message [ 2805.726210] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 08:03:25 (1789128205) === [ 2807.564037] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 2541 sec ========= 08:03:27 (1789128207) [ 2811.381608] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 08:03:31 (1789128211) === [ 2815.634909] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 08:03:35 (1789128215) === [ 2822.853074] Lustre: server umount lustre-MDT0000 complete [ 2826.847184] LustreError: 84607:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789128228 with bad export cookie 17279616917200804688 [ 2826.858814] LustreError: MGC192.168.202.148@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2826.864782] LustreError: Skipped 5 previous similar messages [ 2836.613785] Lustre: server umount lustre-OST0000 complete [ 2840.035055] Lustre: 12954:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789128225/real 1789128225] req@ffff8ed54f707840 x1876034346521856/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789128241 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2840.056576] Lustre: 12954:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 16 previous similar messages [ 2840.063340] 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 [ 2840.073247] Lustre: Skipped 7 previous similar messages [ 2840.453657] Lustre: server umount lustre-OST0001 complete [ 2852.298107] Lustre: DEBUG MARKER: oleg248-server.virtnet: executing unload_modules_local [ 2854.789417] Key type lgssc unregistered [ 2855.007696] LNet: 88912:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2855.010266] LNetError: 88912:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2855.022563] LNet: Removed LNI 192.168.202.148@tcp [ 2855.663268] Key type .llcrypt unregistered [ 2855.665117] Key type ._llcrypt unregistered