[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 3.0.0 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 504472956 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f53f0-0x000f53ff] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5200 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1D87 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1C23 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001BE3 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1C97 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1D27 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1D5F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1c23-0xbffe1c96] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1c22] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1c97-0xbffe1d26] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1d27-0xbffe1d5e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1d5f-0xbffe1d86] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 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.001013] APIC: Switch to symmetric I/O mode setup [ 0.002360] x2apic enabled [ 0.003009] Switched APIC routing to physical x2apic. [ 0.004014] kvm-guest: setup PV IPIs [ 0.007430] ..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.009012] pid_max: default: 32768 minimum: 301 [ 0.010143] LSM: Security Framework initializing [ 0.012020] Yama: becoming mindful. [ 0.013038] SELinux: Initializing. [ 0.014057] *** VALIDATE selinux *** [ 0.022783] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026807] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.027152] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028118] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029120] *** VALIDATE tmpfs *** [ 0.030413] *** VALIDATE proc *** [ 0.031240] *** VALIDATE cgroup *** [ 0.032011] *** VALIDATE cgroup2 *** [ 0.033251] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034153] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.036026] Spectre V2 : User space: Vulnerable [ 0.037009] Speculative Store Bypass: Vulnerable [ 0.040530] debug: unmapping init [mem 0xffffffff9ac59000-0xffffffff9ac60fff] [ 0.042163] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.043593] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.044022] ... version: 2 [ 0.045021] ... bit width: 48 [ 0.046011] ... generic registers: 4 [ 0.047012] ... value mask: 0000ffffffffffff [ 0.048016] ... max period: 00007fffffffffff [ 0.049012] ... fixed-purpose events: 3 [ 0.050010] ... event mask: 000000070000000f [ 0.051264] rcu: Hierarchical SRCU implementation. [ 0.053364] smp: Bringing up secondary CPUs ... [ 0.054498] x86: Booting SMP configuration: [ 0.055023] .... node #0, CPUs: #1 #2 #3 [ 0.059016] smp: Brought up 1 node, 4 CPUs [ 0.061020] smpboot: Max logical packages: 1 [ 0.062011] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.137589] node 0 deferred pages initialised in 73ms [ 0.140157] devtmpfs: initialized [ 0.141218] x86/mm: Memory block size: 128MB [ 0.143757] gcov: version magic: 0x41383552 [ 0.145282] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.146085] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.147263] pinctrl core: initialized pinctrl subsystem [ 0.148215] [ 0.148833] ************************************************************* [ 0.149017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.150012] ** ** [ 0.151018] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.152014] ** ** [ 0.153015] ** This means that this kernel is built to expose internal ** [ 0.154012] ** IOMMU data structures, which may compromise security on ** [ 0.155017] ** your system. ** [ 0.156013] ** ** [ 0.157016] ** If you see this message and you are not debugging the ** [ 0.158013] ** kernel, report this immediately to your vendor! ** [ 0.159013] ** ** [ 0.160017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.161018] ************************************************************* [ 0.162682] NET: Registered protocol family 16 [ 0.163458] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.164071] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.165068] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.166451] cpuidle: using governor menu [ 0.169065] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.171440] PCI: Using configuration type 1 for base access [ 0.173126] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.183027] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.184023] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.185161] cryptd: max_cpu_qlen set to 1000 [ 0.186232] ACPI: Added _OSI(Module Device) [ 0.187020] ACPI: Added _OSI(Processor Device) [ 0.188015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.189014] ACPI: Added _OSI(Processor Aggregator Device) [ 0.192998] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.195544] ACPI: Interpreter enabled [ 0.196072] ACPI: PM: (supports S0 S3 S4 S5) [ 0.197021] ACPI: Using IOAPIC for interrupt routing [ 0.198114] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.199410] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.203000] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.203000] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.203000] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.203000] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.208402] acpiphp: Slot [2] registered [ 0.210117] acpiphp: Slot [5] registered [ 0.211087] acpiphp: Slot [6] registered [ 0.212127] acpiphp: Slot [7] registered [ 0.213086] acpiphp: Slot [8] registered [ 0.214081] acpiphp: Slot [9] registered [ 0.215092] acpiphp: Slot [10] registered [ 0.216105] acpiphp: Slot [3] registered [ 0.217078] acpiphp: Slot [4] registered [ 0.218091] acpiphp: Slot [11] registered [ 0.220080] acpiphp: Slot [12] registered [ 0.221080] acpiphp: Slot [13] registered [ 0.222073] acpiphp: Slot [14] registered [ 0.223074] acpiphp: Slot [15] registered [ 0.225117] acpiphp: Slot [16] registered [ 0.226085] acpiphp: Slot [17] registered [ 0.227081] acpiphp: Slot [18] registered [ 0.229156] acpiphp: Slot [19] registered [ 0.230080] acpiphp: Slot [20] registered [ 0.231077] acpiphp: Slot [21] registered [ 0.232093] acpiphp: Slot [22] registered [ 0.233079] acpiphp: Slot [23] registered [ 0.234075] acpiphp: Slot [24] registered [ 0.235097] acpiphp: Slot [25] registered [ 0.236070] acpiphp: Slot [26] registered [ 0.237103] acpiphp: Slot [27] registered [ 0.239085] acpiphp: Slot [28] registered [ 0.240086] acpiphp: Slot [29] registered [ 0.241069] acpiphp: Slot [30] registered [ 0.242072] acpiphp: Slot [31] registered [ 0.243046] PCI host bridge to bus 0000:00 [ 0.244013] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.246017] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.247015] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.249018] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.251014] pci_bus 0000:00: root bus resource [mem 0x380000000000-0x38007fffffff window] [ 0.253018] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.254158] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.257171] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.260507] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.268014] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.273589] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.277025] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.279022] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.282028] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.284682] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.287867] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.291057] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.293921] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.299018] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.309944] pci 0000:00:02.0: reg 0x20: [mem 0x380000000000-0x380000003fff 64bit pref] [ 0.317025] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.322205] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.330025] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.335023] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.350023] pci 0000:00:05.0: reg 0x20: [mem 0x380000004000-0x380000007fff 64bit pref] [ 0.361563] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.373030] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.381020] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.400020] pci 0000:00:06.0: reg 0x20: [mem 0x380000008000-0x38000000bfff 64bit pref] [ 0.411019] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.420023] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.429032] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.452031] pci 0000:00:07.0: reg 0x20: [mem 0x38000000c000-0x38000000ffff 64bit pref] [ 0.465000] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.472022] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.478016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.493024] pci 0000:00:08.0: reg 0x20: [mem 0x380000010000-0x380000013fff 64bit pref] [ 0.504952] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.511025] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.518025] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.535027] pci 0000:00:09.0: reg 0x20: [mem 0x380000014000-0x380000017fff 64bit pref] [ 0.545861] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.553020] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.563020] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.575016] pci 0000:00:0a.0: reg 0x20: [mem 0x380000018000-0x38000001bfff 64bit pref] [ 0.588382] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.590426] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.594629] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.597435] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.599296] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.604145] iommu: Default domain type: Passthrough [ 0.606491] SCSI subsystem initialized [ 0.608138] ACPI: bus type USB registered [ 0.610124] usbcore: registered new interface driver usbfs [ 0.612214] usbcore: registered new interface driver hub [ 0.614164] usbcore: registered new device driver usb [ 0.616232] pps_core: LinuxPPS API ver. 1 registered [ 0.618022] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.622091] PTP clock support registered [ 0.625053] EDAC MC: Ver: 3.0.0 [ 0.627176] PCI: Using ACPI for IRQ routing [ 0.629895] NetLabel: Initializing [ 0.631012] NetLabel: domain hash size = 128 [ 0.633013] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.635104] NetLabel: unlabeled traffic allowed by default [ 0.638052] vgaarb: loaded [ 0.639245] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.641021] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.651341] clocksource: Switched to clocksource kvm-clock [ 0.759110] VFS: Disk quotas dquot_6.6.0 [ 0.760919] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.763926] *** VALIDATE ramfs *** [ 0.765390] *** VALIDATE hugetlbfs *** [ 0.767158] pnp: PnP ACPI init [ 0.770671] pnp: PnP ACPI: found 6 devices [ 0.792669] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.796205] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.798496] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.800816] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.803330] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.805564] pci_bus 0000:00: resource 8 [mem 0x380000000000-0x38007fffffff window] [ 0.808270] NET: Registered protocol family 2 [ 0.810765] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.815766] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.819375] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.825603] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.829821] TCP: Hash tables configured (established 65536 bind 65536) [ 0.835179] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.838515] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.841830] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.845254] NET: Registered protocol family 1 [ 0.848409] RPC: Registered named UNIX socket transport module. [ 0.850783] RPC: Registered udp transport module. [ 0.852898] RPC: Registered tcp transport module. [ 0.854437] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.857330] NET: Registered protocol family 44 [ 0.859347] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.861826] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.864141] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.866746] PCI: CLS 0 bytes, default 64 [ 0.868528] Unpacking initramfs... [ 2.325483] debug: unmapping init [mem 0xffff8c24fcc54000-0xffff8c24fffbffff] [ 2.332136] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.334453] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.337424] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.841892] Initialise system trusted keyrings [ 2.843803] Key type blacklist registered [ 2.845862] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.855298] zbud: loaded [ 2.858934] *** VALIDATE nfs *** [ 2.860436] *** VALIDATE nfs4 *** [ 2.862179] pstore: using deflate compression [ 2.865717] Platform Keyring initialized [ 2.966952] NET: Registered protocol family 38 [ 2.968473] Key type asymmetric registered [ 2.969735] Asymmetric key parser 'x509' registered [ 2.971565] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.974591] io scheduler mq-deadline registered [ 2.976310] io scheduler kyber registered [ 2.977774] io scheduler bfq registered [ 2.979798] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.982538] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.985053] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.987725] ACPI: Power Button [PWRF] [ 3.070061] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.154890] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.341425] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.433662] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.647658] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.680627] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.715094] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.721908] Non-volatile memory driver v1.3 [ 3.723905] Linux agpgart interface v0.103 [ 3.764702] virtio_blk virtio1: [vda] 133280 512-byte logical blocks (68.2 MB/65.1 MiB) [ 3.769020] vda: detected capacity change from 0 to 68239360 [ 3.787842] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.790963] vdb: detected capacity change from 0 to 1073741824 [ 3.806938] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.810147] vdc: detected capacity change from 0 to 2621440000 [ 3.832711] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.836017] vdd: detected capacity change from 0 to 2621440000 [ 3.852301] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.855463] vde: detected capacity change from 0 to 4294967296 [ 3.872965] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.876086] vdf: detected capacity change from 0 to 4294967296 [ 3.885495] libphy: Fixed MDIO Bus: probed [ 3.900726] usbcore: registered new interface driver usbserial_generic [ 3.903326] usbserial: USB Serial support registered for generic [ 3.905907] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.910409] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.912151] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.914546] mousedev: PS/2 mouse device common for all mice [ 3.917444] rtc_cmos 00:05: RTC can wake from S4 [ 3.920438] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.924386] rtc_cmos 00:05: registered as rtc0 [ 3.926625] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.927317] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.930966] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.932097] intel_pstate: CPU model not supported [ 3.940950] hid: raw HID events driver (C) Jiri Kosina [ 3.943187] usbcore: registered new interface driver usbhid [ 3.945280] usbhid: USB HID core driver [ 3.946975] drop_monitor: Initializing network drop monitor service [ 3.949434] Initializing XFRM netlink socket [ 3.951309] NET: Registered protocol family 10 [ 3.954239] Segment Routing with IPv6 [ 3.955702] NET: Registered protocol family 17 [ 3.959169] mpls_gso: MPLS GSO support [ 3.964686] RAS: Correctable Errors collector initialized. [ 3.966649] AVX version of gcm_enc/dec engaged. [ 3.967965] AES CTR mode by8 optimization enabled [ 4.096438] sched_clock: Marking stable (4096413608, 0)->(5085648409, -989234801) [ 4.101180] registered taskstats version 1 [ 4.110210] Loading compiled-in X.509 certificates [ 4.112678] zswap: loaded using pool lzo/zbud [ 4.138398] Key type big_key registered [ 4.153331] Key type encrypted registered [ 4.155351] ima: No TPM chip found, activating TPM-bypass! [ 4.157798] ima: Allocated hash algorithm: sha1 [ 4.159514] ima: No architecture policies found [ 4.161118] evm: Initialising EVM extended attributes: [ 4.162679] evm: security.selinux [ 4.163804] evm: security.ima [ 4.164750] evm: security.capability [ 4.165939] evm: HMAC attrs: 0x1 [ 4.168624] rtc_cmos 00:05: setting system clock to 2025-11-07 04:24:22 UTC (1762489462) [ 4.175400] debug: unmapping init [mem 0xffffffff9bc03000-0xffffffff9bdfffff] [ 4.178883] debug: unmapping init [mem 0xffffffff9a982000-0xffffffff9ac58fff] [ 4.188113] Write protecting the kernel read-only data: 28672k [ 4.191932] debug: unmapping init [mem 0xffffffff99003000-0xffffffff991fffff] [ 4.195348] debug: unmapping init [mem 0xffffffff99914000-0xffffffff999fffff] [ 4.234276] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 4.241677] systemd[1]: Detected virtualization kvm. [ 4.243499] systemd[1]: Detected architecture x86-64. [ 4.245292] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.281968] systemd[1]: No hostname configured. [ 4.284235] systemd[1]: Set hostname to . [ 4.286619] random: systemd: uninitialized urandom read (16 bytes read) [ 4.289767] systemd[1]: Initializing machine ID from random generator. [ 4.453504] random: systemd: uninitialized urandom read (16 bytes read) [ 4.456860] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 4.462692] random: systemd: uninitialized urandom read (16 bytes read) [ 4.465913] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 4.473550] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Timers. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Local File Systems. [ OK ] Listening on Journal Socket. Starting Create list of required st…ce nodes for the current kernel... Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... [ OK ] Reached target Local Encrypted Volumes. Starting Journal Service... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Swap. [ OK ] Reached target Paths. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 5.166658] device-mapper: uevent: version 1.0.3 [ 5.168809] 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.971178] random: fast init done [ 5.973047] virtio_net virtio0 ens2: renamed from eth0 [ 6.096258] scsi host0: ata_piix [ 6.121413] scsi host1: ata_piix [ 6.122497] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 6.125063] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 10.450273] dracut-initqueue[590]: RTNETLINK answers: File exists [ 10.673095] random: crng init done [ 10.674503] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 11.237303] 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. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 12.493414] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.788791] SELinux: Disabled at runtime. [ 12.851297] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.859480] systemd[1]: Detected virtualization kvm. [ 12.861293] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 13.428976] systemd[1]: initrd-switch-root.service: Succeeded. [ 13.431822] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 13.436259] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 13.440215] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 13.445254] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 13.453050] systemd[1]: Starting Journal Service... Starting Journal Service... [ 13.460454] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Created slice User and Session Slice. [ OK ] Created slice system-getty.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting Huge Pages File System... Mounting POSIX Message Queue File System... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. Mounting Kernel Debug File System... Activating swap /dev/disk/by-label/SWAP... [ OK ] Stopped target Initrd File Systems. [ OK ] Reached target Slices. Starting Apply Kernel Variables... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ 13.614721] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. Starting Remount Root and Kernel File Systems... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.969314] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 14.215083] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 14.428473] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 14.570485] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 14.580342] EDAC sbridge: Ver: 1.1.2 [ 16.321606] Key type dns_resolver registered [ 16.626700] NFS: Registering the id_resolver key type [ 16.628571] Key type id_resolver registered [ 16.630173] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Load/Save Random Seed... Starting Create Volatile Files and Directories... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting 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. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg621-server login: [ 39.898186] spl: loading out-of-tree module taints kernel. [ 43.160798] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 51.358539] Key type ._llcrypt registered [ 51.360178] Key type .llcrypt registered [ 51.455941] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_hostid [ 65.772922] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 66.719627] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 66.728196] alg: No test for adler32 (adler32-zlib) [ 68.017708] Lustre: Lustre: Build Version: 2.16.58_106_gac70ede [ 68.533100] LNet: Added LNI 192.168.206.121@tcp [8/256/0/180] [ 70.226542] Key type lgssc registered [ 71.646936] Lustre: Echo OBD driver; http://www.lustre.org/ [ 79.430559] vdc: vdc1 vdc9 [ 87.956206] vde: vde1 vde9 [ 95.450461] vdf: vdf1 vdf9 [ 107.318654] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 113.522131] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 114.745433] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 114.979398] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 115.040468] Lustre: lustre-MDT0000: new disk, initializing [ 115.336507] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 115.404117] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 117.979195] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 121.321784] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 124.732759] Lustre: lustre-OST0000: new disk, initializing [ 124.735851] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 124.740906] Lustre: Skipped 1 previous similar message [ 124.817200] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 128.336042] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 133.744294] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 133.749539] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 133.809614] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 134.907140] Lustre: lustre-OST0001: new disk, initializing [ 134.910073] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 134.956702] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 138.291442] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 141.375084] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 141.379696] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 141.437395] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 145.990753] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 150.452457] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 159.122655] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing check_logdir /tmp/testlogs/ [ 162.045744] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing yml_node [ 165.193835] Lustre: DEBUG MARKER: Client: 2.16.58.106 [ 166.908406] Lustre: DEBUG MARKER: MDS: 2.16.58.106 [ 168.520126] Lustre: DEBUG MARKER: OSS: 2.16.58.106 [ 169.602316] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Thu Nov 6 23:27:07 EST 2025 [ 180.574808] Lustre: DEBUG MARKER: excepting tests: [ 186.707506] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 192.486069] 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 [ 192.487467] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 192.505472] Lustre: Skipped 1 previous similar message [ 197.133273] LustreError: 10475:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 197.263560] Lustre: server umount lustre-MDT0000 complete [ 199.849301] LustreError: 8207:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1762489658 with bad export cookie 3174699720963201970 [ 199.852519] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 199.867110] LustreError: 8207:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 199.921065] LustreError: 10681:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 199.928788] LustreError: 10681:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 199.970087] Lustre: server umount lustre-OST0000 complete [ 202.426064] LustreError: 10883:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 202.429072] LustreError: 10883:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 202.506655] Lustre: server umount lustre-OST0001 complete [ 208.181546] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing unload_modules_local [ 210.099309] Key type lgssc unregistered [ 210.323851] LNet: 11413:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 210.327626] LNetError: 11413:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 211.370917] LNet: Removed LNI 192.168.206.121@tcp [ 211.958160] Key type .llcrypt unregistered [ 211.959808] Key type ._llcrypt unregistered [ 216.482643] hrtimer: interrupt took 4623685 ns [ 222.570721] Key type ._llcrypt registered [ 222.572433] Key type .llcrypt registered [ 222.646179] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_hostid [ 231.723910] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 232.427083] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 232.481754] alg: No test for adler32 (adler32-zlib) [ 233.444034] Lustre: Lustre: Build Version: 2.16.58_106_gac70ede [ 233.583651] LNet: Added LNI 192.168.206.121@tcp [8/256/0/180] [ 235.205444] Key type lgssc registered [ 235.924806] Lustre: Echo OBD driver; http://www.lustre.org/ [ 240.743843] vdc: vdc1 vdc9 [ 247.218722] vde: vde1 vde9 [ 253.237786] vdf: vdf1 vdf9 [ 264.057311] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 269.927611] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 271.338514] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 271.420890] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 271.477146] Lustre: lustre-MDT0000: new disk, initializing [ 271.745869] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 271.793139] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 274.392983] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 278.025995] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 282.482502] Lustre: lustre-OST0000: new disk, initializing [ 282.485399] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 282.488037] Lustre: Skipped 1 previous similar message [ 282.555427] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 285.793659] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 285.797140] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 285.889152] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 286.159202] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 293.533429] Lustre: lustre-OST0001: new disk, initializing [ 293.535960] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 293.626524] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 297.810885] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 300.662852] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 300.668949] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 300.752618] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 306.492377] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 310.489234] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 319.769928] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 23:29:37 (1762489777) === [ 320.950910] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 23:29:38 (1762489778) [ 331.200987] Lustre: Failing over lustre-MDT0000 [ 331.233932] 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 [ 331.235058] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 331.238494] Lustre: Skipped 1 previous similar message [ 331.342887] LustreError: 17973:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 331.463590] Lustre: server umount lustre-MDT0000 complete [ 335.846085] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 336.141435] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 336.213827] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:42 to 0x240000400:65) [ 336.219504] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 338.808661] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 341.479193] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 346.301705] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 23:30:03 (1762489803) [ 352.357386] LustreError: 19097:0:(client.c:1370:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff8c2449a6ad80 x1848104390329856/t0(0) o104->lustre-OST0001@192.168.206.21@tcp:15/16 lens 328/224 e 0 to 0 dl 0 ref 1 fl Rpc:QU/0/ffffffff rc 0/-1 job:'' uid:4294967295 gid:4294967295 projid:4294967295 [ 357.958951] Lustre: Failing over lustre-MDT0000 [ 358.123368] LustreError: 19290:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 358.126344] LustreError: 19290:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 358.253122] Lustre: server umount lustre-MDT0000 complete [ 363.676216] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 364.013308] 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 [ 364.022757] Lustre: Skipped 1 previous similar message [ 364.130112] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 364.221836] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:106 to 0x240000400:129) [ 364.222062] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 367.082649] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 369.122322] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 369.128616] Lustre: Skipped 1 previous similar message [ 370.200571] Lustre: *** cfs_fail_loc=193, val=0*** [ 372.957089] Lustre: Failing over lustre-MDT0000 [ 373.131303] LustreError: 20331:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 373.133658] LustreError: 20331:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 373.255157] Lustre: server umount lustre-MDT0000 complete [ 377.877802] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 378.062553] 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 [ 378.069839] Lustre: Skipped 1 previous similar message [ 378.151452] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 378.215828] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:106 to 0x240000400:161) [ 378.215908] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:161) [ 379.172196] Lustre: 12624:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762489820/real 1762489820] req@ffff8c2447ed7100 x1848104390333696/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762489836 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 380.757968] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 383.461443] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 383.475296] Lustre: Skipped 1 previous similar message [ 386.717470] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 23:30:44 (1762489844) [ 390.624138] Lustre: 12622:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762489832/real 1762489832] req@ffff8c2448b9b800 x1848104390348800/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762489848 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 390.650043] Lustre: 12622:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 394.883537] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 400.822600] Lustre: 22228:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 413.406239] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 415.696710] Lustre: 23075:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 427.214936] Lustre: *** cfs_fail_loc=198, val=0*** [ 434.617554] Lustre: Failing over lustre-MDT0000 [ 434.658055] 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 [ 434.659360] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 434.683558] Lustre: Skipped 1 previous similar message [ 434.699973] Lustre: Skipped 2 previous similar messages [ 434.873580] LustreError: 23410:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 434.878592] LustreError: 23410:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 435.018371] Lustre: server umount lustre-MDT0000 complete [ 440.494626] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 440.985242] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 441.108506] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:202 to 0x240000400:225) [ 441.112703] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:203 to 0x280000400:225) [ 443.965565] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 450.398557] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 23:31:48 (1762489908) [ 451.266825] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_1c ldiskfs special test [ 452.185894] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 23:31:49 (1762489909) [ 453.049085] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_2 ldiskfs special test [ 454.174747] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 23:31:51 (1762489911) [ 455.150904] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 455.153041] Lustre: Skipped 1 previous similar message [ 459.899549] Lustre: *** cfs_fail_loc=193, val=0*** [ 467.117544] Lustre: Failing over lustre-MDT0000 [ 467.250190] LustreError: 24937:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 467.252270] LustreError: 24937:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 467.347887] Lustre: server umount lustre-MDT0000 complete [ 471.405686] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 471.616470] 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 [ 471.625863] Lustre: Skipped 1 previous similar message [ 471.849157] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:266 to 0x240000400:289) [ 471.849316] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 474.176937] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 477.153914] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 477.166781] Lustre: Skipped 1 previous similar message [ 477.285887] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002341:0x4f:0x0]/0x1f0): rc = 0 [ 477.299970] LustreError: 25794:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 485.858611] Lustre: 12622:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762489928/real 1762489928] req@ffff8c257445f800 x1848104390467072/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762489944 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 485.878155] Lustre: 12622:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 490.597920] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 23:32:28 (1762489948) [ 491.410144] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4b ldiskfs special test [ 492.257504] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 23:32:30 (1762489950) [ 492.968902] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4c ldiskfs special test [ 493.810218] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 23:32:31 (1762489951) [ 494.730373] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4d ldiskfs only test [ 495.739785] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 23:32:33 (1762489953) [ 496.744991] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_4e ldiskfs only test [ 498.016177] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 23:32:35 (1762489955) [ 512.993131] 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 [ 512.997352] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 513.003673] Lustre: Skipped 1 previous similar message [ 513.136333] LustreError: 26691:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 513.139576] LustreError: 26691:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 513.236450] Lustre: server umount lustre-MDT0000 complete [ 515.897703] LustreError: 15077:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1762489974 with bad export cookie 8689113934101182561 [ 515.900768] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 515.906738] LustreError: 15077:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 517.977527] Lustre: server umount lustre-OST0000 complete [ 522.537122] Lustre: server umount lustre-OST0001 complete [ 526.611578] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_hostid [ 530.931943] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 536.586787] vdc: vdc1 vdc9 [ 542.152178] vde: vde1 vde9 [ 548.207528] vdf: vdf1 vdf9 [ 557.087829] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 562.732931] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 562.810319] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 562.865278] Lustre: lustre-MDT0000: new disk, initializing [ 563.115138] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 563.120167] Lustre: Skipped 1 previous similar message [ 563.156624] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 565.534375] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 568.798103] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 572.701190] Lustre: lustre-OST0000: new disk, initializing [ 572.703959] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 572.706700] Lustre: Skipped 1 previous similar message [ 574.325182] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 574.329697] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 574.423096] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 576.520399] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 583.328649] Lustre: lustre-OST0001: new disk, initializing [ 583.331707] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 585.480801] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 585.484418] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 585.569386] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 587.585664] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 594.403127] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 597.208508] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 608.693127] Lustre: *** cfs_fail_loc=193, val=0*** [ 608.696195] Lustre: Skipped 3 previous similar messages [ 617.184812] Lustre: Failing over lustre-MDT0000 [ 617.394652] LustreError: 32659:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 617.397708] LustreError: 32659:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 617.528424] Lustre: server umount lustre-MDT0000 complete [ 622.633892] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 622.832033] 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 [ 622.842635] Lustre: Skipped 1 previous similar message [ 623.057113] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:42 to 0x240000400:65) [ 623.060912] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 626.296256] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 628.195083] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 628.200303] Lustre: Skipped 1 previous similar message [ 629.942371] Lustre: *** cfs_fail_loc=190, val=3*** [ 629.942489] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000401:0x4f:0x0]/0x2ea): rc = 0 [ 629.948813] LustreError: 33607:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 629.955069] LustreError: 33607:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 632.992146] Lustre: *** cfs_fail_loc=191, val=3*** [ 632.994126] Lustre: Skipped 1 previous similar message [ 636.824768] Lustre: Failing over lustre-MDT0000 [ 637.034101] Lustre: server umount lustre-MDT0000 complete [ 637.856141] Lustre: 12624:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762490079/real 1762490079] req@ffff8c2441eb9880 x1848104390534272/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762490095 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 637.887182] Lustre: 12624:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 642.746535] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 642.749688] Lustre: Skipped 3 previous similar messages [ 642.826875] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:42 to 0x240000400:97) [ 642.834782] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:97) [ 644.850093] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 647.839686] Lustre: Failing over lustre-MDT0000 [ 648.079763] Lustre: server umount lustre-MDT0000 complete [ 652.600666] Lustre: *** cfs_fail_loc=190, val=3*** [ 653.082150] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:129) [ 653.082315] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:42 to 0x240000400:129) [ 653.921070] Lustre: 12624:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762490096/real 1762490096] req@ffff8c2441eb9880 x1848104390545024/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762490112 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 655.075336] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 655.649261] Lustre: *** cfs_fail_loc=190, val=3*** [ 658.019678] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 658.023275] Lustre: Skipped 1 previous similar message [ 660.231121] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000401:0x46:0x0]/0x380): rc = 0 [ 660.242251] LustreError: 35907:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -2 [ 665.008708] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 23:35:22 (1762490122) [ 670.420937] Lustre: *** cfs_fail_loc=193, val=0*** [ 670.422735] Lustre: Skipped 3 previous similar messages [ 676.842546] Lustre: Failing over lustre-MDT0000 [ 676.990465] LustreError: 36505:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 676.992268] LustreError: 36505:0:(obd_class.h:479:obd_check_dev()) Skipped 17 previous similar messages [ 677.062519] Lustre: server umount lustre-MDT0000 complete [ 681.033963] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 681.037334] LustreError: Skipped 2 previous similar messages [ 681.216418] 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 [ 681.228463] Lustre: Skipped 2 previous similar messages [ 681.358415] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:170 to 0x240000400:193) [ 681.359289] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 683.226715] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 686.125178] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b71:0x4f:0x0]/0x3b6): rc = 0 [ 686.125351] Lustre: *** cfs_fail_loc=190, val=2*** [ 686.133882] Lustre: Skipped 1 previous similar message [ 686.137212] LustreError: 37412:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 693.079158] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b71:0x46:0x0]/0x3a4): rc = 0 [ 693.090228] LustreError: 37557:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 694.752139] Lustre: 12623:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762490137/real 1762490137] req@ffff8c256ccedf80 x1848104390599040/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762490153 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 694.771300] Lustre: 12623:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 696.160893] Lustre: *** cfs_fail_loc=191, val=3*** [ 696.162570] Lustre: Skipped 6 previous similar messages [ 700.716397] Lustre: Failing over lustre-MDT0000 [ 700.991958] Lustre: server umount lustre-MDT0000 complete [ 706.415311] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:170 to 0x240000400:225) [ 706.416171] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 708.730955] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 711.651817] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 711.661686] Lustre: Skipped 3 previous similar messages [ 717.792246] Lustre: 12622:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762490160/real 1762490160] req@ffff8c244711d180 x1848104390611072/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762490176 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 717.819982] Lustre: 12622:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 718.595457] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 23:36:16 (1762490176) [ 726.030581] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 731.682683] Lustre: 39947:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 743.468645] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 745.817621] Lustre: 40793:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 763.400188] Lustre: *** cfs_fail_loc=193, val=0*** [ 763.402744] Lustre: Skipped 3 previous similar messages [ 770.377111] Lustre: Failing over lustre-MDT0000 [ 770.584086] LustreError: 41271:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 770.587447] LustreError: 41271:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 770.690921] Lustre: server umount lustre-MDT0000 complete [ 774.997489] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 775.002886] LustreError: Skipped 1 previous similar message [ 775.200318] 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 [ 775.207947] Lustre: Skipped 4 previous similar messages [ 775.350507] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 775.353129] Lustre: Skipped 3 previous similar messages [ 775.431515] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:266 to 0x280000400:289) [ 775.439870] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:266 to 0x240000400:289) [ 777.726403] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 780.265665] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 780.268956] Lustre: Skipped 1 previous similar message [ 781.263174] Lustre: *** cfs_fail_loc=190, val=3*** [ 781.264935] Lustre: Skipped 2 previous similar messages [ 781.266338] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b11:0x4f:0x0]/0x322): rc = 0 [ 781.270487] LustreError: 42181:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 789.472089] Lustre: 12625:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762490231/real 1762490231] req@ffff8c257c74fb80 x1848104390673920/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762490247 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 789.500714] Lustre: 12625:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 791.826329] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 23:37:29 (1762490249) [ 803.616305] Lustre: *** cfs_fail_loc=193, val=0*** [ 803.618039] Lustre: Skipped 3 previous similar messages [ 810.492157] Lustre: Failing over lustre-MDT0000 [ 810.691996] Lustre: server umount lustre-MDT0000 complete [ 814.881961] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:330 to 0x240000400:353) [ 814.882262] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 817.419451] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 820.244437] Lustre: *** cfs_fail_loc=190, val=1*** [ 820.246381] Lustre: Skipped 1 previous similar message [ 826.719179] LustreError: 44204:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 826.726247] LustreError: 44204:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 832.895852] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 23:38:10 (1762490290) [ 833.867959] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_9 test scrub speed only on ldiskfs [ 834.938230] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 23:38:12 (1762490292) [ 841.828431] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 848.136167] Lustre: 45593:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 859.614158] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 861.813504] Lustre: 46437:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 874.615854] Lustre: *** cfs_fail_loc=193, val=0*** [ 874.617640] Lustre: Skipped 3 previous similar messages [ 881.810598] Lustre: Failing over lustre-MDT0000 [ 882.114798] Lustre: server umount lustre-MDT0000 complete [ 887.055666] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:394 to 0x240000400:417) [ 887.062896] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:417) [ 889.682717] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 893.047220] Lustre: *** cfs_fail_loc=190, val=1*** [ 893.047682] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200003ab1:0x4f:0x0]/0x26c): rc = 0 [ 893.051811] Lustre: Skipped 5 previous similar messages [ 893.059758] LustreError: 47657:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 893.066102] LustreError: 47657:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 895.981620] Lustre: Failing over lustre-MDT0000 [ 896.396785] Lustre: server umount lustre-MDT0000 complete [ 903.186954] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:394 to 0x240000400:449) [ 903.187058] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:449) [ 906.282973] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 908.266829] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 908.272012] Lustre: Skipped 5 previous similar messages [ 909.693958] Lustre: Failing over lustre-MDT0000 [ 909.837508] LustreError: 48750:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 909.840385] LustreError: 48750:0:(obd_class.h:479:obd_check_dev()) Skipped 23 previous similar messages [ 909.947146] Lustre: server umount lustre-MDT0000 complete [ 912.801466] Lustre: 12624:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762490355/real 1762490355] req@ffff8c25516e1180 x1848104390794880/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762490371 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 912.824451] Lustre: 12624:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 914.753636] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 914.761192] LustreError: Skipped 3 previous similar messages [ 914.979621] 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 [ 914.996245] Lustre: Skipped 7 previous similar messages [ 915.174735] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:394 to 0x240000400:481) [ 915.174739] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:394 to 0x280000400:481) [ 917.911414] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 929.529983] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 23:39:46 (1762490386) [ 930.859848] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_11 ldiskfs special test [ 932.404761] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 23:39:49 (1762490389) [ 942.356238] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 948.192836] Lustre: 50953:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 959.151127] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 970.032276] Lustre: *** cfs_fail_loc=195, val=0*** [ 970.034053] Lustre: Skipped 3 previous similar messages [ 972.789486] Lustre: Failing over lustre-OST0000 [ 972.916501] Lustre: server umount lustre-OST0000 complete [ 976.356963] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 976.365303] LustreError: 42683:0:(ldlm_lib.c:1179: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. [ 976.380488] LustreError: 42683:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 978.635375] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 980.215344] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 980.268945] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 982.288251] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 983.978318] LustreError: 40816:0:(osd_object.c:462:osd_check_lma()) lustre-OST0000: FID-in-LMA [0x240000400:0x21f:0x0] does not match the object self-fid [0x240000400:0x21e:0x0]: rc = -78 [ 983.990402] LustreError: 40816:0:(osd_object.c:462:osd_check_lma()) Skipped 5 previous similar messages [ 984.031788] LustreError: 40935:0:(osd_object.c:590:osd_object_init()) lustre-OST0000: lookup [0x240000400:0x221:0x0]/0x5c0 failed: rc = -2 [ 1171.111886] LustreError: 40935:0:(osd_object.c:590:osd_object_init()) lustre-OST0000: lookup [0x240000400:0x221:0x0]/0x5c0 failed: rc = -2 [ 1171.300885] LustreError: 40935:0:(osd_object.c:462:osd_check_lma()) lustre-OST0000: FID-in-LMA [0x240000400:0x212:0x0] does not match the object self-fid [0x240000400:0x211:0x0]: rc = -78 [ 1171.309504] LustreError: 40935:0:(osd_object.c:462:osd_check_lma()) Skipped 10 previous similar messages [ 1172.886335] LustreError: 53082:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-OST0000: can't get bonus, rc = -2 [ 1172.893692] LustreError: 53082:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 1179.257790] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 23:43:56 (1762490636) [ 1182.803973] Lustre: *** cfs_fail_loc=196, val=0*** [ 1182.806077] Lustre: Skipped 63 previous similar messages [ 1185.989348] Lustre: Failing over lustre-OST0000 [ 1186.027093] LustreError: 53674:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 1186.028906] LustreError: 53674:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1186.040336] Lustre: server umount lustre-OST0000 complete [ 1188.836792] 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 [ 1188.846351] Lustre: Skipped 1 previous similar message [ 1188.854886] LustreError: 42682:0:(ldlm_lib.c:1179: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. [ 1191.311574] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1191.314425] Lustre: Skipped 5 previous similar messages [ 1191.318127] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1193.204461] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1193.272625] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1193.273922] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1193.284114] Lustre: Skipped 4 previous similar messages [ 1194.928863] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1393.157300] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 23:47:30 (1762490850) [ 1394.320757] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_14 ldiskfs special test [ 1395.522623] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 23:47:33 (1762490853) [ 1411.553368] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1411.556322] Lustre: Skipped 2 previous similar messages [ 1415.127678] Lustre: server umount lustre-MDT0000 complete [ 1418.658224] LustreError: 30786:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1762490876 with bad export cookie 8689113934101310654 [ 1418.677537] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1424.810157] Lustre: server umount lustre-OST0000 complete [ 1428.630363] Lustre: server umount lustre-OST0001 complete [ 1435.129874] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_hostid [ 1442.207485] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 1452.036609] vdc: vdc1 vdc9 [ 1461.603774] vde: vde1 vde9 [ 1461.616848] vde: vde1 vde9 [ 1470.132694] vdf: vdf1 vdf9 [ 1483.246827] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 1489.503931] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1489.610684] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1489.675601] Lustre: lustre-MDT0000: new disk, initializing [ 1490.070854] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1493.822463] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1498.268732] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1503.263827] Lustre: lustre-OST0000: new disk, initializing [ 1503.273167] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1503.276822] Lustre: Skipped 1 previous similar message [ 1505.022786] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 1505.027356] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 1505.242186] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 1508.608847] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1518.033508] Lustre: lustre-OST0001: new disk, initializing [ 1518.050914] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1519.446087] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 1519.466687] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 1519.622546] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 1524.310211] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1533.438266] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1536.321223] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1547.526799] Lustre: *** cfs_fail_loc=193, val=0*** [ 1547.528389] Lustre: Skipped 63 previous similar messages [ 1556.062374] Lustre: Failing over lustre-MDT0000 [ 1556.635778] Lustre: server umount lustre-MDT0000 complete [ 1563.541721] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 1563.545773] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:42 to 0x240000400:65) [ 1566.499645] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1569.237112] LustreError: 62008:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -17 [ 1569.241892] LustreError: 62008:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 1 previous similar message [ 1575.904392] Lustre: 12625:0:(client.c:2468:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1762491018/real 1762491018] req@ffff8c2546699500 x1848104390995456/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1762491034 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1575.924934] Lustre: 12625:0:(client.c:2468:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 1588.140991] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 23:50:45 (1762491045) [ 1598.221511] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 1605.541065] Lustre: 63984:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1605.545907] Lustre: 63984:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 1620.712939] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1623.826359] Lustre: 64832:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1645.113217] Lustre: Failing over lustre-MDT0000 [ 1645.138155] Lustre: *** cfs_fail_loc=199, val=0*** [ 1645.140109] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 1645.143563] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x3:0x0]: rc = 0 [ 1645.148470] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 1645.160952] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 1645.176074] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 1645.191686] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 1645.196610] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 1645.203317] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xf:0x0]: rc = 0 [ 1645.212968] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x11:0x0]: rc = 0 [ 1645.220051] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x36:0x0]: rc = 0 [ 1645.235448] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 1645.246282] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 1645.254384] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 1645.263852] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 1645.272830] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 1645.280236] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 1645.287344] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 1645.294516] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 1645.308697] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 1645.326316] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 1645.336749] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 1645.351683] Lustre: 65152:0:(scrub.c:1084:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 1645.539069] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1645.543154] Lustre: Skipped 1 previous similar message [ 1645.730848] Lustre: server umount lustre-MDT0000 complete [ 1652.291925] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 1652.301545] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x36:0x0]: rc = 0 [ 1652.309152] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x3:0x0]: rc = 0 [ 1652.321475] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 1652.329087] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xe:0x0]: rc = 0 [ 1652.334599] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 1652.340001] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xd:0x0]: rc = 0 [ 1652.348527] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xf:0x0]: rc = 0 [ 1652.357286] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 1652.365192] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xc:0x0]: rc = 0 [ 1652.372318] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 1652.380134] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0xa:0x0]: rc = 0 [ 1652.387479] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xb:0x0]: rc = 0 [ 1652.393556] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 1652.399966] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 1652.416673] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 1652.428841] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 1652.444124] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 1652.464644] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 1652.486329] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 1652.509259] Lustre: 65612:0:(osd_scrub.c:942:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 1653.305426] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:106 to 0x240000400:129) [ 1653.314102] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 1656.223431] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1665.745763] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 23:52:02 (1762491122) [ 1667.091784] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_17a ldiskfs only test [ 1668.631336] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 23:52:05 (1762491125) [ 1670.011244] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_17b ldiskfs only test [ 1671.532345] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 23:52:08 (1762491128) [ 1685.341447] Lustre: Failing over lustre-MDT0000 [ 1685.769395] Lustre: server umount lustre-MDT0000 complete [ 1692.987976] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:170 to 0x240000400:193) [ 1692.991975] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 1695.726308] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1700.476144] Lustre: Failing over lustre-MDT0000 [ 1700.741566] LustreError: 67537:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 1700.743980] LustreError: 67537:0:(obd_class.h:479:obd_check_dev()) Skipped 31 previous similar messages [ 1700.888738] Lustre: server umount lustre-MDT0000 complete [ 1706.897481] Lustre: lustre-MDT0000: reset Object Index mappings [ 1707.785222] 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 [ 1707.807295] Lustre: Skipped 9 previous similar messages [ 1707.937574] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1707.940688] Lustre: Skipped 6 previous similar messages [ 1708.053946] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 1708.057117] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:170 to 0x240000400:225) [ 1711.621621] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1713.126437] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1713.131822] Lustre: Skipped 6 previous similar messages [ 1720.609739] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 23:52:57 (1762491177) [ 1726.465948] Lustre: server umount lustre-MDT0000 complete [ 1730.222357] LustreError: 59228:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1762491188 with bad export cookie 8689113934101370231 [ 1730.230441] LustreError: 59228:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 1739.850592] Lustre: server umount lustre-OST0000 complete [ 1753.730187] Lustre: server umount lustre-OST0001 complete [ 1785.888919] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 1791.008295] LustreError: 70177:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.121@tcp: failed processing log, type 4: rc = -110 [ 1821.887735] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1828.415296] Lustre: Failing over lustre-OST0000 [ 1828.606332] Lustre: server umount lustre-OST0000 complete [ 1863.396301] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 1868.512318] LustreError: 72018:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.121@tcp: failed processing log, type 4: rc = -110 [ 1899.627738] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1907.063418] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 23:56:04 (1762491364) [ 1908.296357] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_20 ldiskfs only test [ 1909.816319] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 23:56:07 (1762491367) [ 1911.013124] Lustre: DEBUG MARKER: SKIP: sanity-scrub test_21 needs >= 2 MDTs [ 1912.591196] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 23:56:09 (1762491369) [ 1917.107599] Lustre: server umount lustre-OST0000 complete [ 1940.088948] LustreError: 74443:0:(osd_index.c:203:__osd_xattr_load_by_oid()) lustre-MDT0000: can't get bonus, rc = -2 [ 1940.094108] LustreError: 74443:0:(osd_index.c:203:__osd_xattr_load_by_oid()) Skipped 9 previous similar messages [ 1944.363117] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1950.166683] Lustre: Failing over lustre-MDT0000 [ 1950.778563] Lustre: server umount lustre-MDT0000 complete [ 1972.912798] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1979.868540] Lustre: DEBUG MARKER: === sanity-scrub: start setup 23:57:17 (1762491437) === [ 1982.386526] Lustre: server umount lustre-MDT0000 complete [ 1992.172926] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_hostid [ 2000.001253] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 2009.034358] vdc: vdc1 vdc9 [ 2017.062250] vde: vde1 vde9 [ 2026.079522] vdf: vdf1 vdf9 [ 2041.407289] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing load_modules_local [ 2050.095482] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2050.340056] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2050.384394] Lustre: lustre-MDT0000: new disk, initializing [ 2050.822213] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2054.568535] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2065.494390] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2065.660413] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2069.352745] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2078.472652] Lustre: lustre-OST0001: new disk, initializing [ 2078.475754] Lustre: Skipped 1 previous similar message [ 2078.482564] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2078.490475] Lustre: Skipped 2 previous similar messages [ 2080.253824] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 2080.256568] Lustre: Skipped 1 previous similar message [ 2080.259286] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 2080.418558] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 2083.565428] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2091.567576] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2094.149585] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2094.151445] Lustre: Skipped 1 previous similar message [ 2102.283651] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 23:59:19 (1762491559) === [ 2103.573574] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 1932 sec ========= 23:59:20 (1762491560) [ 2104.873498] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 23:59:22 (1762491562) === [ 2107.229687] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 23:59:24 (1762491564) === [ 2110.951672] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2110.961811] Lustre: Skipped 1 previous similar message [ 2116.135953] Lustre: server umount lustre-MDT0000 complete [ 2119.412444] LustreError: 80180:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1762491577 with bad export cookie 8689113934101380717 [ 2119.412855] LustreError: MGC192.168.206.121@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2119.424190] LustreError: 80180:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2119.446752] LustreError: Skipped 5 previous similar messages [ 2119.503339] Lustre: server umount lustre-OST0000 complete [ 2123.048116] Lustre: server umount lustre-OST0001 complete [ 2132.083993] Lustre: DEBUG MARKER: oleg621-server.virtnet: executing unload_modules_local [ 2134.559356] Key type lgssc unregistered [ 2134.831280] LNet: 83941:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2134.844408] LNetError: 83941:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2134.864341] LNet: Removed LNI 192.168.206.121@tcp [ 2135.575141] Key type .llcrypt unregistered [ 2135.579023] Key type ._llcrypt unregistered