[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 492103909 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2400.000 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001011] APIC: Switch to symmetric I/O mode setup [ 0.002384] x2apic enabled [ 0.003010] Switched APIC routing to physical x2apic. [ 0.004012] kvm-guest: setup PV IPIs [ 0.007548] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 0.008020] Calibrating delay loop (skipped) preset value.. 4800.00 BogoMIPS (lpj=2400000) [ 0.009013] pid_max: default: 32768 minimum: 301 [ 0.011077] LSM: Security Framework initializing [ 0.012053] Yama: becoming mindful. [ 0.013041] SELinux: Initializing. [ 0.015086] *** VALIDATE selinux *** [ 0.022860] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027172] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028160] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029116] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030140] *** VALIDATE tmpfs *** [ 0.032384] *** VALIDATE proc *** [ 0.033261] *** VALIDATE cgroup *** [ 0.034008] *** VALIDATE cgroup2 *** [ 0.035278] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.036144] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.037008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.038035] Spectre V2 : User space: Vulnerable [ 0.039009] Speculative Store Bypass: Vulnerable [ 0.042198] debug: unmapping init [mem 0xffffffff90a59000-0xffffffff90a60fff] [ 0.044869] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.045738] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.046023] ... version: 2 [ 0.047014] ... bit width: 48 [ 0.048024] ... generic registers: 4 [ 0.048939] ... value mask: 0000ffffffffffff [ 0.049022] ... max period: 00007fffffffffff [ 0.050018] ... fixed-purpose events: 3 [ 0.051018] ... event mask: 000000070000000f [ 0.052319] rcu: Hierarchical SRCU implementation. [ 0.054472] smp: Bringing up secondary CPUs ... [ 0.055688] x86: Booting SMP configuration: [ 0.056028] .... node #0, CPUs: #1 #2 #3 [ 0.059508] smp: Brought up 1 node, 4 CPUs [ 0.061011] smpboot: Max logical packages: 1 [ 0.062020] smpboot: Total of 4 processors activated (19200.00 BogoMIPS) [ 0.146026] node 0 deferred pages initialised in 80ms [ 0.149381] devtmpfs: initialized [ 0.150273] x86/mm: Memory block size: 128MB [ 0.153188] gcov: version magic: 0x41383552 [ 0.156278] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.160096] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.164405] pinctrl core: initialized pinctrl subsystem [ 0.166191] [ 0.166920] ************************************************************* [ 0.170016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.173015] ** ** [ 0.176014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.178012] ** ** [ 0.181015] ** This means that this kernel is built to expose internal ** [ 0.184016] ** IOMMU data structures, which may compromise security on ** [ 0.187015] ** your system. ** [ 0.190018] ** ** [ 0.193017] ** If you see this message and you are not debugging the ** [ 0.196014] ** kernel, report this immediately to your vendor! ** [ 0.199020] ** ** [ 0.201012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.203013] ************************************************************* [ 0.205963] NET: Registered protocol family 16 [ 0.208475] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.212065] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.215067] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.219089] cpuidle: using governor menu [ 0.221948] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.224451] PCI: Using configuration type 1 for base access [ 0.226146] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.236113] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.238030] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.241092] cryptd: max_cpu_qlen set to 1000 [ 0.244166] ACPI: Added _OSI(Module Device) [ 0.245019] ACPI: Added _OSI(Processor Device) [ 0.247011] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.249018] ACPI: Added _OSI(Processor Aggregator Device) [ 0.252860] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.259592] ACPI: Interpreter enabled [ 0.261068] ACPI: PM: (supports S0 S3 S4 S5) [ 0.262014] ACPI: Using IOAPIC for interrupt routing [ 0.264120] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.266397] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.278121] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.281054] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.286026] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.291109] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.299000] acpiphp: Slot [2] registered [ 0.302190] acpiphp: Slot [5] registered [ 0.305142] acpiphp: Slot [6] registered [ 0.307170] acpiphp: Slot [7] registered [ 0.309148] acpiphp: Slot [8] registered [ 0.312085] acpiphp: Slot [9] registered [ 0.314129] acpiphp: Slot [10] registered [ 0.315134] acpiphp: Slot [3] registered [ 0.316086] acpiphp: Slot [4] registered [ 0.317085] acpiphp: Slot [11] registered [ 0.319087] acpiphp: Slot [12] registered [ 0.320120] acpiphp: Slot [13] registered [ 0.321097] acpiphp: Slot [14] registered [ 0.323145] acpiphp: Slot [15] registered [ 0.325151] acpiphp: Slot [16] registered [ 0.328565] acpiphp: Slot [17] registered [ 0.330119] acpiphp: Slot [18] registered [ 0.332141] acpiphp: Slot [19] registered [ 0.334124] acpiphp: Slot [20] registered [ 0.336120] acpiphp: Slot [21] registered [ 0.338118] acpiphp: Slot [22] registered [ 0.340122] acpiphp: Slot [23] registered [ 0.341115] acpiphp: Slot [24] registered [ 0.343128] acpiphp: Slot [25] registered [ 0.347091] acpiphp: Slot [26] registered [ 0.349158] acpiphp: Slot [27] registered [ 0.351151] acpiphp: Slot [28] registered [ 0.354144] acpiphp: Slot [29] registered [ 0.357136] acpiphp: Slot [30] registered [ 0.359163] acpiphp: Slot [31] registered [ 0.361070] PCI host bridge to bus 0000:00 [ 0.363021] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.367036] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.370023] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.373024] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.376024] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.379039] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.381278] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.385130] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.388388] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.399720] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.404944] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.407017] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.409019] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.411026] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.414810] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.418997] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.422042] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.425909] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.431018] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.445016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.448957] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.456412] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.462024] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.470017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.488017] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.497094] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.506019] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.516015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.541018] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.552373] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.557014] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.564016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.578014] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.588208] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.596014] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.604018] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.620016] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.632574] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.638013] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.644017] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.658016] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.670277] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.677018] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.684018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.700020] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.712207] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.715546] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.719571] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.722456] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.725654] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.733098] iommu: Default domain type: Passthrough [ 0.735473] SCSI subsystem initialized [ 0.738186] ACPI: bus type USB registered [ 0.740122] usbcore: registered new interface driver usbfs [ 0.743093] usbcore: registered new interface driver hub [ 0.745134] usbcore: registered new device driver usb [ 0.748208] pps_core: LinuxPPS API ver. 1 registered [ 0.750011] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.753059] PTP clock support registered [ 0.756061] EDAC MC: Ver: 3.0.0 [ 0.758160] PCI: Using ACPI for IRQ routing [ 0.759637] NetLabel: Initializing [ 0.761021] NetLabel: domain hash size = 128 [ 0.763013] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.765098] NetLabel: unlabeled traffic allowed by default [ 0.768173] vgaarb: loaded [ 0.771317] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.773026] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.779489] clocksource: Switched to clocksource kvm-clock [ 0.891046] VFS: Disk quotas dquot_6.6.0 [ 0.892732] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.895456] *** VALIDATE ramfs *** [ 0.896991] *** VALIDATE hugetlbfs *** [ 0.899251] pnp: PnP ACPI init [ 0.902262] pnp: PnP ACPI: found 6 devices [ 0.923842] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.927828] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.931169] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.934321] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.937177] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.940443] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.943841] NET: Registered protocol family 2 [ 0.947201] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.954052] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.959612] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.966658] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.970829] TCP: Hash tables configured (established 65536 bind 65536) [ 0.974728] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.978557] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.981845] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.985524] NET: Registered protocol family 1 [ 0.989260] RPC: Registered named UNIX socket transport module. [ 0.992031] RPC: Registered udp transport module. [ 0.994184] RPC: Registered tcp transport module. [ 0.996152] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.998959] NET: Registered protocol family 44 [ 1.000937] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.003371] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.005576] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.007479] PCI: CLS 0 bytes, default 64 [ 1.009393] Unpacking initramfs... [ 2.480123] debug: unmapping init [mem 0xffff8f547cc54000-0xffff8f547ffbffff] [ 2.487356] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.490225] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.496375] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 2.982350] Initialise system trusted keyrings [ 2.984191] Key type blacklist registered [ 2.986422] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.995900] zbud: loaded [ 2.999075] *** VALIDATE nfs *** [ 3.000140] *** VALIDATE nfs4 *** [ 3.001935] pstore: using deflate compression [ 3.005759] Platform Keyring initialized [ 3.109464] NET: Registered protocol family 38 [ 3.111227] Key type asymmetric registered [ 3.112750] Asymmetric key parser 'x509' registered [ 3.114645] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.117802] io scheduler mq-deadline registered [ 3.119363] io scheduler kyber registered [ 3.120835] io scheduler bfq registered [ 3.122770] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.125883] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.129048] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.132365] ACPI: Power Button [PWRF] [ 3.138233] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.143949] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.156539] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.163530] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.177314] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.206090] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.234133] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.239546] Non-volatile memory driver v1.3 [ 3.241432] Linux agpgart interface v0.103 [ 3.278650] virtio_blk virtio1: [vda] 134784 512-byte logical blocks (69.0 MB/65.8 MiB) [ 3.281875] vda: detected capacity change from 0 to 69009408 [ 3.297765] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.300577] vdb: detected capacity change from 0 to 1073741824 [ 3.317185] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.320163] vdc: detected capacity change from 0 to 2621440000 [ 3.338322] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.341415] vdd: detected capacity change from 0 to 2621440000 [ 3.358552] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.363843] vde: detected capacity change from 0 to 4294967296 [ 3.379353] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.382398] vdf: detected capacity change from 0 to 4294967296 [ 3.394863] libphy: Fixed MDIO Bus: probed [ 3.400470] usbcore: registered new interface driver usbserial_generic [ 3.403568] usbserial: USB Serial support registered for generic [ 3.406371] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.411845] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.413871] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.417133] mousedev: PS/2 mouse device common for all mice [ 3.420825] rtc_cmos 00:05: RTC can wake from S4 [ 3.423691] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.425169] rtc_cmos 00:05: registered as rtc0 [ 3.429655] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.433522] intel_pstate: CPU model not supported [ 3.438543] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.438805] hid: raw HID events driver (C) Jiri Kosina [ 3.445205] usbcore: registered new interface driver usbhid [ 3.447893] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.448043] usbhid: USB HID core driver [ 3.448280] drop_monitor: Initializing network drop monitor service [ 3.456538] Initializing XFRM netlink socket [ 3.459035] NET: Registered protocol family 10 [ 3.462528] Segment Routing with IPv6 [ 3.464164] NET: Registered protocol family 17 [ 3.466480] mpls_gso: MPLS GSO support [ 3.473263] RAS: Correctable Errors collector initialized. [ 3.475233] AVX version of gcm_enc/dec engaged. [ 3.476904] AES CTR mode by8 optimization enabled [ 3.563749] sched_clock: Marking stable (3563722762, 0)->(4461007412, -897284650) [ 3.568677] registered taskstats version 1 [ 3.571448] Loading compiled-in X.509 certificates [ 3.573926] zswap: loaded using pool lzo/zbud [ 3.603794] Key type big_key registered [ 3.620168] Key type encrypted registered [ 3.622190] ima: No TPM chip found, activating TPM-bypass! [ 3.625086] ima: Allocated hash algorithm: sha1 [ 3.627209] ima: No architecture policies found [ 3.629568] evm: Initialising EVM extended attributes: [ 3.631908] evm: security.selinux [ 3.633605] evm: security.ima [ 3.635161] evm: security.capability [ 3.637083] evm: HMAC attrs: 0x1 [ 3.639824] rtc_cmos 00:05: setting system clock to 2026-05-16 09:14:22 UTC (1778922862) [ 3.646431] debug: unmapping init [mem 0xffffffff91a03000-0xffffffff91bfffff] [ 3.649946] debug: unmapping init [mem 0xffffffff90782000-0xffffffff90a58fff] [ 3.659102] Write protecting the kernel read-only data: 28672k [ 3.663122] debug: unmapping init [mem 0xffffffff8ee03000-0xffffffff8effffff] [ 3.666473] debug: unmapping init [mem 0xffffffff8f714000-0xffffffff8f7fffff] [ 3.705225] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.716633] systemd[1]: Detected virtualization kvm. [ 3.719849] systemd[1]: Detected architecture x86-64. [ 3.722821] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.753883] systemd[1]: No hostname configured. [ 3.755810] systemd[1]: Set hostname to . [ 3.758375] random: systemd: uninitialized urandom read (16 bytes read) [ 3.760947] systemd[1]: Initializing machine ID from random generator. [ 3.801499] random: ln: uninitialized urandom read (6 bytes read) [ 3.893371] random: systemd: uninitialized urandom read (16 bytes read) [ 3.896335] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 3.902574] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 3.907878] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Timers. [ OK ] Reached target Paths. [ OK ] Listening on udev Control Socket. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... Starting Setup Virtual Console... [ OK ] Reached target Sockets. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Memstrack Anylazing Service. Starting Journal Service... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.595684] device-mapper: uevent: version 1.0.3 [ 4.598343] 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.459533] random: fast init done [ 5.495260] virtio_net virtio0 ens2: renamed from eth0 [ 5.497090] scsi host0: ata_piix [ 5.538936] scsi host1: ata_piix [ 5.540824] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.543669] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 10.171622] random: crng init done [ 10.182489] random: 7 urandom warning(s) missed due to ratelimiting [ 11.241504] dracut-initqueue[590]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ 13.177919] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Reached target Remote File Systems. [ 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 dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 16.370796] printk: systemd: 26 output lines suppressed due to ratelimiting [ 17.535709] SELinux: Disabled at runtime. [ 17.693859] 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) [ 17.707686] systemd[1]: Detected virtualization kvm. [ 17.711763] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 19.795545] systemd[1]: initrd-switch-root.service: Succeeded. [ 19.802601] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 19.820502] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 19.829880] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 19.839682] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 19.861284] systemd[1]: Starting Journal Service... Starting Journal Service... [ 19.882810] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Created slice system-serial\x2dgetty.slice. Activating swap /dev/disk/by-label/SWAP... Mounting Kernel Debug File System... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Reached target Local Encrypted Volumes. Mounting POSIX Message Queue File System... [ 20.099709] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [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-getty.slice. Mounting Huge Pages File System... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice User and Session Slice. Starting Remount Root and Kernel File Systems... Starting Apply Kernel Variables... [ OK ] Reached target Paths. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Reached target Slices. [ OK ] Listening on Process Core Dump Socket. [ OK ] Reached target rpc_pipefs.target. [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 21.641330] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 22.881824] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 23.211355] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 23.649907] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 23.728148] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (7s / no limit) [** ] A start job is running for Configur…-only root support (8s / no limit) [*** ] A start job is running for Configur…-only root support (8s / no limit) [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ ***] A start job is running for Configur…only root support (10s / no limit)[ 30.234623] Key type dns_resolver registered [ **] A start job is running for Configur…only root support (10s / no limit) [ *] A start job is running for Configur…only root support (11s / no limit)[ 31.326079] NFS: Registering the id_resolver key type [ 31.330874] Key type id_resolver registered [ 31.332607] Key type id_legacy registered [ **] A start job is running for Configur…only root support (11s / no limit) [ ***] A start job is running for Configur…only root support (12s / no limit) [ 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 Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started D-Bus System Message Bus. [ OK ] Started irqbalance daemon. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target sshd-keygen.target. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started OpenSSH server daemon. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ 40.488017] hrtimer: interrupt took 10459515 ns [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg401-server login: [ 79.533057] spl: loading out-of-tree module taints kernel. [ 86.382406] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 100.268762] Key type ._llcrypt registered [ 100.276966] Key type .llcrypt registered [ 100.492972] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_hostid [ 122.048926] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_modules_local [ 124.121618] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 124.179457] alg: No test for adler32 (adler32-zlib) [ 126.163733] Lustre: Lustre: Build Version: 2.17.53_3_g0d061c0 [ 127.559644] LNet: Added LNI 192.168.204.101@tcp [8/256/0/180] [ 129.329895] Key type lgssc registered [ 131.725437] Lustre: Echo OBD driver; http://www.lustre.org/ [ 144.194557] vdc: vdc1 vdc9 [ 155.036253] vde: vde1 vde9 [ 166.772363] vdf: vdf1 vdf9 [ 187.121664] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_modules_local [ 196.468974] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 197.835741] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 198.200452] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 198.340546] Lustre: lustre-MDT0000: new disk, initializing [ 198.796106] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 198.857911] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 203.500559] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 208.636831] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 214.758501] Lustre: lustre-OST0000: new disk, initializing [ 214.762358] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 214.774345] Lustre: Skipped 1 previous similar message [ 214.870373] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 218.399204] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 218.415153] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 218.649595] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 221.537192] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 233.078482] Lustre: lustre-OST0001: new disk, initializing [ 233.082701] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 233.208803] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 239.333349] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 239.344190] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 239.475261] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 241.899963] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 253.875330] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 265.013497] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 271.896665] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing check_logdir /tmp/testlogs/ [ 277.559177] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing yml_node [ 283.864258] Lustre: DEBUG MARKER: Client: 2.17.53.3 [ 287.508864] Lustre: DEBUG MARKER: MDS: 2.17.53.3 [ 290.737831] Lustre: DEBUG MARKER: OSS: 2.17.53.3 [ 292.278104] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity ============----- Sat May 16 05:19:09 EDT 2026 [ 310.934962] Lustre: DEBUG MARKER: - need MDS1_VERSION <= 2.16.61-1-g89cf292a8c2 (34682115 <= 34618625) for LU-18938, skip 360 [ 312.584610] Lustre: DEBUG MARKER: - need MDS1_VERSION < v2_14_55-100-g8a84c7f9c7 (34682115 < 34486116) for LU-14927, skip 0f [ 314.168754] Lustre: DEBUG MARKER: excepting tests: 42a 42c 42b 118c 118d 407 119i 817 411a 130b 130c 130d 130e 130f 130g [ 315.705644] Lustre: DEBUG MARKER: skipping tests SLOW=no: 27m 60i 64b 68 71 135 136 230d 300o 842 51b 51c 51e 834 [ 317.194804] Lustre: DEBUG MARKER: === sanity: start setup 05:19:34 (1778923174) === [ 321.157808] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing check_config_client /mnt/lustre [ 339.872925] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 343.315930] Lustre: 11168:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 347.093378] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 351.047254] Lustre: DEBUG MARKER: === sanity: finish setup 05:20:08 (1778923208) === [ 358.372734] Lustre: DEBUG MARKER: == sanity test 60a: llog_test run from kernel module and test llog_reader ========================================================== 05:20:15 (1778923215) [ 361.717490] Lustre: DEBUG MARKER: SKIP: sanity test_60a missing subtest run-llog.sh [ 363.583931] Lustre: DEBUG MARKER: == sanity test 60b: limit repeated messages from CERROR/CWARN ========================================================== 05:20:20 (1778923220) [ 372.225263] Lustre: DEBUG MARKER: == sanity test 60c: unlink file when mds full ============ 05:20:29 (1778923229) [ 592.505281] Lustre: DEBUG MARKER: == sanity test 60d: test printk console message masking == 05:24:09 (1778923449) [ 599.987976] Lustre: DEBUG MARKER: == sanity test 60e: no space while new llog is being created ========================================================== 05:24:17 (1778923457) [ 601.189498] Lustre: *** cfs_fail_loc=15b, val=0*** [ 601.194446] Lustre: *** cfs_fail_loc=15b, val=0*** [ 601.199986] LustreError: 5792:0:(llog_cat.c:583:llog_cat_add_rec()) lustre-OST0001-osc-MDT0000: initialization error: rc = -28 [ 607.435228] Lustre: DEBUG MARKER: == sanity test 60f: change debug_path works ============== 05:24:24 (1778923464) [ 615.265922] Lustre: DEBUG MARKER: == sanity test 60g: transaction abort won't cause MDT hung ========================================================== 05:24:32 (1778923472) [ 616.344913] Lustre: *** cfs_fail_loc=19a, val=0*** [ 617.232349] Lustre: *** cfs_fail_loc=19a, val=0*** [ 618.235541] Lustre: *** cfs_fail_loc=19a, val=0*** [ 620.469258] Lustre: *** cfs_fail_loc=19a, val=0*** [ 620.470855] Lustre: Skipped 1 previous similar message [ 624.769058] Lustre: *** cfs_fail_loc=19a, val=0*** [ 624.777475] Lustre: Skipped 3 previous similar messages [ 633.033160] Lustre: *** cfs_fail_loc=19a, val=0*** [ 633.037211] Lustre: Skipped 6 previous similar messages [ 649.249445] Lustre: *** cfs_fail_loc=19a, val=0*** [ 649.259462] Lustre: Skipped 14 previous similar messages [ 682.378114] Lustre: *** cfs_fail_loc=19a, val=0*** [ 682.385027] Lustre: Skipped 32 previous similar messages [ 738.687615] Lustre: DEBUG MARKER: == sanity test 60h: striped directory with missing stripes can be accessed ========================================================== 05:26:35 (1778923595) [ 740.512943] Lustre: DEBUG MARKER: SKIP: sanity test_60h Need at least 2 MDTs [ 742.258567] Lustre: DEBUG MARKER: SKIP: sanity test_60i skipping SLOW test 60i [ 743.992685] Lustre: DEBUG MARKER: == sanity test 60j: llog_reader reports corruptions ====== 05:26:41 (1778923601) [ 745.890421] Lustre: DEBUG MARKER: SKIP: sanity test_60j ldiskfs only test [ 747.861469] Lustre: DEBUG MARKER: == sanity test 61a: mmap() writes don't make sync hang ========================================================================== 05:26:45 (1778923605) [ 755.570534] Lustre: DEBUG MARKER: == sanity test 61b: mmap() of unstriped file is successful ========================================================== 05:26:52 (1778923612) [ 762.512720] Lustre: DEBUG MARKER: == sanity test 63a: Verify oig_wait interruption does not crash ================================================================= 05:26:59 (1778923619) [ 834.729947] Lustre: DEBUG MARKER: == sanity test 63b: async write errors should be returned to fsync ============================================================= 05:28:11 (1778923691) [ 850.325764] Lustre: DEBUG MARKER: == sanity test 64a: verify filter grant calculations (in kernel) =============================================================== 05:28:27 (1778923707) [ 860.180728] Lustre: DEBUG MARKER: SKIP: sanity test_64b skipping SLOW test 64b [ 862.006403] Lustre: DEBUG MARKER: == sanity test 64c: verify grant shrink ================== 05:28:39 (1778923719) [ 871.850273] Lustre: DEBUG MARKER: == sanity test 64d: check grant limit exceed ============= 05:28:49 (1778923729) [ 936.071966] Lustre: DEBUG MARKER: == sanity test 64e: check grant consumption (no grant allocation) ========================================================== 05:29:53 (1778923793) [ 940.202290] Lustre: *** cfs_fail_loc=725, val=0*** [ 944.850047] Lustre: *** cfs_fail_loc=725, val=0*** [ 954.237977] Lustre: DEBUG MARKER: == sanity test 64f: check grant consumption (with grant allocation) ========================================================== 05:30:10 (1778923810) [ 971.388551] Lustre: DEBUG MARKER: == sanity test 64g: grant shrink on MDT ================== 05:30:28 (1778923828) [ 1023.686054] Lustre: DEBUG MARKER: == sanity test 64h: grant shrink on read ================= 05:31:20 (1778923880) [ 1045.209984] Lustre: DEBUG MARKER: == sanity test 64i: shrink on reconnect ================== 05:31:42 (1778923902) [ 1053.546513] Lustre: *** cfs_fail_loc=513, val=17*** [ 1053.550853] LustreError: 12377:0:(service.c:2344:ptlrpc_server_handle_req_in()) drop incoming rpc opc 17, x1865335930154368 [ 1055.256703] Lustre: Failing over lustre-OST0000 [ 1055.376503] Lustre: server umount lustre-OST0000 complete [ 1056.737791] 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 [ 1061.857679] LustreError: 12377:0:(ldlm_lib.c:1180: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. [ 1061.881575] LustreError: 12377:0:(ldlm_lib.c:1180:target_handle_connect()) Skipped 3 previous similar messages [ 1064.334233] LustreError: 6576:0:(ldlm_lib.c:1180:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.1@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1066.977215] LustreError: 12332:0:(ldlm_lib.c:1180: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. [ 1069.462028] LustreError: 11776:0:(ldlm_lib.c:1180:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.1@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1072.588517] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 1072.600494] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1074.088563] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1074.482319] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1074.488165] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1079.043729] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [ 1085.930862] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 1087.508755] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 1098.897451] Lustre: DEBUG MARKER: == sanity test 64j: check grants on re-done rpc ========== 05:32:36 (1778923956) [ 1100.149177] Lustre: *** cfs_fail_loc=256, val=0*** [ 1109.469671] Lustre: DEBUG MARKER: == sanity test 65a: directory with no stripe info ======== 05:32:46 (1778923966) [ 1115.617196] Lustre: DEBUG MARKER: == sanity test 65b: directory setstripe -S stripe_size*2 -i 0 -c 1 ========================================================== 05:32:53 (1778923973) [ 1121.833721] Lustre: DEBUG MARKER: == sanity test 65c: directory setstripe -S stripe_size*4 -i 1 -c 1 ========================================================== 05:32:59 (1778923979) [ 1127.515400] Lustre: DEBUG MARKER: == sanity test 65d: directory setstripe -S stripe_size -c stripe_count ========================================================== 05:33:04 (1778923984) [ 1133.903053] Lustre: DEBUG MARKER: == sanity test 65e: directory setstripe defaults ========= 05:33:11 (1778923991) [ 1140.460322] Lustre: DEBUG MARKER: == sanity test 65f: dir setstripe permission (should return error) ============================================================= 05:33:17 (1778923997) [ 1146.516446] Lustre: DEBUG MARKER: == sanity test 65g: directory setstripe -d =============== 05:33:23 (1778924003) [ 1152.686612] Lustre: DEBUG MARKER: == sanity test 65h: directory stripe info inherit ============================================================================== 05:33:30 (1778924010) [ 1160.509404] Lustre: DEBUG MARKER: == sanity test 65i: various tests to set root directory striping ========================================================== 05:33:37 (1778924017) [ 1167.730146] Lustre: DEBUG MARKER: == sanity test 65j: set default striping on root directory (bug 6367)=========================================================== 05:33:45 (1778924025) [ 1175.098256] Lustre: DEBUG MARKER: == sanity test 65k: validate manual striping works properly with deactivated OSCs ========================================================== 05:33:52 (1778924032) [ 1177.135229] 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 [ 1177.153107] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 1177.160693] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1178.122230] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 1197.366696] Lustre: setting import lustre-OST0000_UUID INACTIVE by administrator request [ 1213.955800] 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 [ 1213.965056] Lustre: Skipped 1 previous similar message [ 1213.974439] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 1213.985893] LustreError: lustre-OST0000-osc-MDT0000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1213.996310] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1214.007690] Lustre: Skipped 1 previous similar message [ 1219.070488] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 1219.312551] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 1239.367107] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 1257.638305] Lustre: lustre-OST0001-osc-MDT0000: Connection to lustre-OST0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1257.664396] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 1257.680297] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1257.700069] Lustre: lustre-OST0001-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1263.492674] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0001-osc-MDT0000.ost_server_uuid 50 [ 1263.761790] Lustre: DEBUG MARKER: os[cp].lustre-OST0001-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 1271.683439] Lustre: DEBUG MARKER: == sanity test 65l: lfs find on -1 stripe dir ================================================================================== 05:35:28 (1778924128) [ 1278.765454] Lustre: DEBUG MARKER: == sanity test 65m: normal user can't set filesystem default stripe ========================================================== 05:35:35 (1778924135) [ 1285.050897] Lustre: DEBUG MARKER: == sanity test 65n: don't inherit default layout from root for new subdirectories ========================================================== 05:35:42 (1778924142) [ 1295.833570] Lustre: DEBUG MARKER: SKIP: sanity test_65n needs >= 2 MDTs [ 1311.309963] Lustre: DEBUG MARKER: == sanity test 65o: pool inheritance for mdt component === 05:36:07 (1778924167) [ 1338.350679] Lustre: DEBUG MARKER: == sanity test 65p: setstripe with yaml file and huge number ========================================================== 05:36:35 (1778924195) [ 1345.326075] Lustre: DEBUG MARKER: == sanity test 65q: setstripe with >=8E offset should fail ========================================================== 05:36:42 (1778924202) [ 1352.488712] Lustre: DEBUG MARKER: == sanity test 65r: prevent all-zero offsets ============= 05:36:49 (1778924209) [ 1360.400165] Lustre: DEBUG MARKER: == sanity test 66: update inode blocks count on client ========================================================================= 05:36:57 (1778924217) [ 1374.995329] Lustre: DEBUG MARKER: == sanity test 69: verify oa2dentry return -ENOENT doesn't LBUG ================================================================ 05:37:12 (1778924232) [ 1376.909856] Lustre: *** cfs_fail_loc=217, val=0*** [ 1376.915285] Lustre: Skipped 1 previous similar message [ 1379.660067] Lustre: *** cfs_fail_loc=217, val=0*** [ 1379.661936] Lustre: Skipped 5 previous similar messages [ 1387.459382] Lustre: DEBUG MARKER: == sanity test 70a: verify health_check, health_write don't explode (on OST) ========================================================== 05:37:24 (1778924244) [ 1401.932898] Lustre: DEBUG MARKER: SKIP: sanity test_71 skipping SLOW test 71 [ 1403.881956] Lustre: DEBUG MARKER: == sanity test 72a: Test that remove suid works properly (bug5695) ============================================================== 05:37:40 (1778924260) [ 1412.144566] Lustre: DEBUG MARKER: == sanity test 72b: Test that we keep mode setting if without file data changed (bug 24226) ========================================================== 05:37:49 (1778924269) [ 1419.559265] Lustre: DEBUG MARKER: == sanity test 73: multiple MDC requests (should not deadlock) ========================================================== 05:37:56 (1778924276) [ 1452.620487] Lustre: DEBUG MARKER: == sanity test 74a: ldlm_enqueue freed-export error path, ls (shouldn't LBUG) ========================================================== 05:38:30 (1778924310) [ 1460.067335] Lustre: DEBUG MARKER: == sanity test 74b: ldlm_enqueue freed-export error path, touch (shouldn't LBUG) ========================================================== 05:38:37 (1778924317) [ 1468.057408] Lustre: DEBUG MARKER: == sanity test 74c: ldlm_lock_create error path, (shouldn't LBUG) ========================================================== 05:38:45 (1778924325) [ 1474.679944] Lustre: DEBUG MARKER: == sanity test 76a: confirm clients recycle inodes properly ============================================================== 05:38:51 (1778924331) [ 1563.911445] Lustre: DEBUG MARKER: == sanity test 76b: confirm clients recycle directory inodes properly ============================================================== 05:40:20 (1778924420) [ 1620.429535] Lustre: DEBUG MARKER: == sanity test 77a: normal checksum read/write operation ========================================================== 05:41:17 (1778924477) [ 1629.889398] Lustre: DEBUG MARKER: == sanity test 77b: checksum error on client write, read ========================================================== 05:41:26 (1778924486) [ 1630.307956] LustreError: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.204.1@tcp inode [0x200000406:0xc34:0x0] object 0x240000400:3786 extent [0-1048575]: client csum bff304e8, server csum bff304e7 [ 1633.697741] Lustre: DEBUG MARKER: set checksum type to crc32, rc = 0 [ 1635.341738] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc34:0x0] object 0x240000400:3786 extent [0-1048575], client returned csum 6eb069cc (type 1), server csum a44c9a1 (type 1) [ 1638.385984] Lustre: DEBUG MARKER: set checksum type to adler, rc = 0 [ 1639.952526] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc34:0x0] object 0x240000400:3786 extent [0-1048575], client returned csum e7f9ec2e (type 2), server csum 9de4ecf2 (type 2) [ 1642.778091] Lustre: DEBUG MARKER: set checksum type to crc32c, rc = 0 [ 1644.365103] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc34:0x0] object 0x240000400:3786 extent [1048576-2097151], client returned csum 6f9ede1f (type 4), server csum f0121d1e (type 4) [ 1647.853618] Lustre: DEBUG MARKER: set checksum type to t10ip512, rc = 0 [ 1649.484958] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc34:0x0] object 0x240000400:3786 extent [1048576-2097151], client returned csum 4d35d5aa (type 10), server csum 5cc7d50b (type 10) [ 1652.908387] Lustre: DEBUG MARKER: set checksum type to t10ip4K, rc = 0 [ 1654.478981] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc34:0x0] object 0x240000400:3786 extent [0-1048575], client returned csum 8a12fccd (type 20), server csum fdb9fe07 (type 20) [ 1658.101717] Lustre: DEBUG MARKER: set checksum type to t10crc512, rc = 0 [ 1662.670944] Lustre: DEBUG MARKER: set checksum type to t10crc4K, rc = 0 [ 1664.083332] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc34:0x0] object 0x240000400:3786 extent [0-1048575], client returned csum b2d6f6f3 (type 80), server csum 92ef69e (type 80) [ 1664.103833] LustreError: Skipped 1 previous similar message [ 1666.494594] Lustre: DEBUG MARKER: set checksum type to crc32c, rc = 0 [ 1674.205267] Lustre: DEBUG MARKER: == sanity test 77c: checksum error on client read with debug ========================================================== 05:42:11 (1778924531) [ 1681.943613] Lustre: 6580:0:(tgt_handler.c:2005:dump_all_bulk_pages()) dumping checksum data to /tmp/lustre-log-checksum_dump-ost-[0x200000406:0xc35:0x0]:[0-1048575]-73d19a7a-bff304e7 [ 1681.987262] LustreError: dumping log to /tmp/lustre-log.1778924540.6580 [ 1682.222934] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc35:0x0] object 0x240000400:3787 extent [0-1048575], client returned csum 73d19a7a (type 4), server csum bff304e7 (type 4) [ 1715.621590] Lustre: DEBUG MARKER: == sanity test 77d: checksum error on OST direct write, read ========================================================== 05:42:52 (1778924572) [ 1716.099350] LustreError: lustre-OST0001: BAD WRITE CHECKSUM: from 12345-192.168.204.1@tcp inode [0x200000406:0xc37:0x0] object 0x280000400:3777 extent [0-1048575]: client csum b5ea7f3c, server csum b5ea7f3b [ 1719.118051] LustreError: lustre-OST0001: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.204.1@tcp inode [0x200000406:0xc37:0x0] object 0x280000400:3777 extent [1048576-2097151], client returned csum fe0f685f (type 4), server csum b5ea7f3b (type 4) [ 1726.701228] Lustre: DEBUG MARKER: == sanity test 77f: repeat checksum error on write (expect error) ========================================================== 05:43:03 (1778924583) [ 1728.308704] Lustre: DEBUG MARKER: set checksum type to crc32, rc = 0 [ 1728.601253] LustreError: 20377:0:(tgt_grant.c:745:tgt_grant_check()) lustre-OST0000: cli 2a308916-b21d-4272-afc4-2be0dcaed176 claims 1703936 GRANT, real grant 0 [ 1728.619187] LustreError: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.204.1@tcp inode [0x200000406:0xc38:0x0] object 0x240000400:3788 extent [0-1048575]: client csum b2f1b12, server csum b2f1b11 [ 1732.062790] Lustre: DEBUG MARKER: set checksum type to adler, rc = 0 [ 1732.413703] LustreError: lustre-OST0001: BAD WRITE CHECKSUM: from 12345-192.168.204.1@tcp inode [0x200000406:0xc39:0x0] object 0x280000400:3778 extent [0-1048575]: client csum 19eeae62, server csum 19eeae61 [ 1732.455694] LustreError: Skipped 18 previous similar messages [ 1735.581292] Lustre: DEBUG MARKER: set checksum type to crc32c, rc = 0 [ 1737.332095] LustreError: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.204.1@tcp inode [0x200000406:0xc3a:0x0] object 0x240000400:3789 extent [5242880-6291455]: client csum b5ea7f3c, server csum b5ea7f3b [ 1737.349243] LustreError: Skipped 19 previous similar messages [ 1739.283049] Lustre: DEBUG MARKER: set checksum type to t10ip512, rc = 0 [ 1743.279711] Lustre: DEBUG MARKER: set checksum type to t10ip4K, rc = 0 [ 1746.913562] Lustre: DEBUG MARKER: set checksum type to t10crc512, rc = 0 [ 1747.255345] LustreError: lustre-OST0001: BAD WRITE CHECKSUM: from 12345-192.168.204.1@tcp inode [0x200000406:0xc3d:0x0] object 0x280000400:3780 extent [0-1048575]: client csum 887488b6, server csum 887488b5 [ 1747.285802] LustreError: Skipped 39 previous similar messages [ 1750.629081] Lustre: DEBUG MARKER: set checksum type to t10crc4K, rc = 0 [ 1760.195524] Lustre: DEBUG MARKER: set checksum type to crc32c, rc = 0 [ 1761.816304] Lustre: DEBUG MARKER: == sanity test 77g: checksum error on OST write, read ==== 05:43:39 (1778924619) [ 1763.614188] Lustre: *** cfs_fail_loc=21a, val=0*** [ 1763.616678] LustreError: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.204.1@tcp inode [0x200000406:0xc3f:0x0] object 0x240000400:3792 extent [0-1048575]: client csum bff304e7, server csum e40b1e12 [ 1763.626531] LustreError: Skipped 30 previous similar messages [ 1768.731654] Lustre: *** cfs_fail_loc=21b, val=0*** [ 1780.594631] Lustre: DEBUG MARKER: == sanity test 77k: enable/disable checksum correctly ==== 05:43:57 (1778924637) [ 1781.760508] Lustre: Setting parameter lustre.osc.lustre*.checksums=0 in log params [ 1789.997609] Lustre: Modifying parameter lustre.osc.lustre*.checksums=1 in log params [ 1795.855418] Lustre: Disabling parameter lustre.osc.lustre*.checksums= in log params [ 1815.236835] Lustre: Setting parameter lustre.osc.lustre*.checksums=0 in log params [ 1819.883422] Lustre: DEBUG MARKER: == sanity test 77l: preferred checksum type is remembered after reconnected ========================================================== 05:44:36 (1778924676) [ 1822.158834] Lustre: DEBUG MARKER: set checksum type to invalid, rc = 22 [ 1824.009046] Lustre: DEBUG MARKER: set checksum type to crc32, rc = 0 [ 1828.128268] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state IDLE osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1829.855286] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in IDLE state after 0 sec [ 1834.395849] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1836.269948] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in FULL state after 0 sec [ 1838.163419] Lustre: DEBUG MARKER: set checksum type to adler, rc = 0 [ 1843.322803] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state IDLE osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1856.552399] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in IDLE state after 10 sec [ 1860.850456] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1862.470760] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in FULL state after 0 sec [ 1864.399867] Lustre: DEBUG MARKER: set checksum type to crc32c, rc = 0 [ 1868.661865] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state IDLE osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1881.543231] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in IDLE state after 10 sec [ 1885.467768] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1887.400180] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in FULL state after 0 sec [ 1889.248837] Lustre: DEBUG MARKER: set checksum type to t10ip512, rc = 0 [ 1894.940308] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state IDLE osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1901.023835] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in IDLE state after 4 sec [ 1904.960681] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1906.578829] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in FULL state after 0 sec [ 1908.367282] Lustre: DEBUG MARKER: set checksum type to t10ip4K, rc = 0 [ 1912.329611] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state IDLE osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1921.668490] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in IDLE state after 7 sec [ 1925.771826] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1927.598394] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in FULL state after 0 sec [ 1929.490469] Lustre: DEBUG MARKER: set checksum type to t10crc512, rc = 0 [ 1933.703583] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state IDLE osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1943.275833] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in IDLE state after 7 sec [ 1947.880970] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1949.509487] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in FULL state after 0 sec [ 1951.453502] Lustre: DEBUG MARKER: set checksum type to t10crc4K, rc = 0 [ 1955.868889] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state IDLE osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1968.691599] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in IDLE state after 10 sec [ 1972.930343] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid 50 [ 1974.387942] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8107458800.ost_server_uuid in FULL state after 0 sec [ 1981.752609] Lustre: DEBUG MARKER: set checksum type to crc32c, rc = 0 [ 1983.583565] Lustre: DEBUG MARKER: == sanity test 77m: Verify checksum_speed is correctly read ========================================================== 05:47:20 (1778924840) [ 1990.825877] Lustre: DEBUG MARKER: == sanity test 77n: Verify read from a hole inside contiguous blocks with T10PI ========================================================== 05:47:27 (1778924847) [ 1992.952518] Lustre: DEBUG MARKER: SKIP: sanity test_77n f77n.sanity blocks not contiguous around hole [ 1995.015107] Lustre: DEBUG MARKER: == sanity test 77o: Verify checksum_type for server (mdt and ofd(obdfilter)) ========================================================== 05:47:32 (1778924852) [ 2007.735070] Lustre: DEBUG MARKER: == sanity test 78: handle large O_DIRECT writes correctly ====================================================================== 05:47:44 (1778924864) [ 2017.650333] Lustre: DEBUG MARKER: == sanity test 79: df report consistency check =========== 05:47:55 (1778924875) [ 2045.518909] Lustre: DEBUG MARKER: == sanity test 80: Page eviction is equally fast at high offsets too ========================================================== 05:48:22 (1778924902) [ 2054.855358] Lustre: DEBUG MARKER: == sanity test 81a: OST should retry write when get -ENOSPC ========================================================================= 05:48:31 (1778924911) [ 2056.518774] Lustre: *** cfs_fail_loc=228, val=0*** [ 2064.064755] Lustre: DEBUG MARKER: == sanity test 81b: OST should return -ENOSPC when retry still fails ================================================================= 05:48:41 (1778924921) [ 2066.041095] Lustre: *** cfs_fail_loc=228, val=0*** [ 2073.024798] Lustre: DEBUG MARKER: == sanity test 99: cvs strange file/directory operations ========================================================== 05:48:50 (1778924930) [ 2101.085707] Lustre: DEBUG MARKER: == sanity test 100: check local port using privileged port ========================================================== 05:49:18 (1778924958) [ 2111.255528] Lustre: DEBUG MARKER: == sanity test 101a: check read-ahead for random reads === 05:49:28 (1778924968) [ 2316.135438] Lustre: DEBUG MARKER: == sanity test 101b: check stride-io mode read-ahead =========================================================================== 05:52:53 (1778925173) [ 2351.643754] Lustre: DEBUG MARKER: == sanity test 101c: check stripe_size aligned read-ahead ========================================================== 05:53:28 (1778925208) [ 2448.443563] Lustre: DEBUG MARKER: == sanity test 101d: file read with and without read-ahead enabled ========================================================== 05:55:05 (1778925305) [ 2792.466173] Lustre: DEBUG MARKER: == sanity test 101e: check read-ahead for small read(1k) for small files(500k) ========================================================== 06:00:49 (1778925649) [ 2900.440741] Lustre: DEBUG MARKER: == sanity test 101f: check mmap read performance ========= 06:02:37 (1778925757) [ 2913.088417] Lustre: DEBUG MARKER: == sanity test 101g: Big bulk(4/16 MiB) readahead ======== 06:02:50 (1778925770) [ 3022.638909] Lustre: DEBUG MARKER: == sanity test 101h: Readahead should cover current read window ========================================================== 06:04:39 (1778925879) [ 3050.242366] Lustre: DEBUG MARKER: == sanity test 101i: allow current readahead to exceed reservation ========================================================== 06:05:07 (1778925907) [ 3063.576886] Lustre: DEBUG MARKER: == sanity test 101j: A complete read block should be submitted when no RA ========================================================== 06:05:20 (1778925920) [ 3138.172663] Lustre: DEBUG MARKER: == sanity test 101m: read ahead for small file and last stripe of the file ========================================================== 06:06:34 (1778925994) [ 3140.231666] Lustre: DEBUG MARKER: SKIP: sanity test_101m need >= 2.13.57 and ldiskfs for fallocate [ 3142.398144] Lustre: DEBUG MARKER: == sanity test 102a: user xattr test ============================================================================================ 06:06:39 (1778925999) [ 3154.656395] Lustre: DEBUG MARKER: == sanity test 102b: getfattr/setfattr for trusted.lov EAs ========================================================== 06:06:51 (1778926011) [ 3169.980409] Lustre: DEBUG MARKER: == sanity test 102c: non-root getfattr/setfattr for lustre.lov EAs ===================================================================== 06:07:06 (1778926026) [ 3179.511258] Lustre: DEBUG MARKER: == sanity test 102d: tar restore stripe info from tarfile,not keep osts ========================================================== 06:07:16 (1778926036) [ 3205.657818] Lustre: DEBUG MARKER: == sanity test 102f: tar copy files, not keep osts ======= 06:07:41 (1778926061) [ 3237.030182] Lustre: DEBUG MARKER: == sanity test 102h: grow xattr from inside inode to external block ========================================================== 06:08:12 (1778926092) [ 3240.720455] Lustre: DEBUG MARKER: save trusted.big on /mnt/lustre/f102h.sanity [ 3243.634560] Lustre: DEBUG MARKER: save trusted.sml on /mnt/lustre/f102h.sanity [ 3246.436589] Lustre: DEBUG MARKER: grow trusted.sml on /mnt/lustre/f102h.sanity [ 3248.766472] Lustre: DEBUG MARKER: trusted.big still valid after growing trusted.sml [ 3259.467903] Lustre: DEBUG MARKER: == sanity test 102ha: grow xattr from inside inode to external inode ========================================================== 06:08:35 (1778926115) [ 3262.618865] Lustre: DEBUG MARKER: save trusted.big on /mnt/lustre/f102ha.sanity [ 3265.669697] Lustre: DEBUG MARKER: save trusted.sml on /mnt/lustre/f102ha.sanity [ 3267.834886] Lustre: DEBUG MARKER: grow trusted.sml on /mnt/lustre/f102ha.sanity [ 3269.933395] Lustre: DEBUG MARKER: trusted.big still valid after growing trusted.sml [ 3274.469130] Lustre: DEBUG MARKER: save trusted.big on /mnt/lustre/f102ha.sanity [ 3282.890178] Lustre: DEBUG MARKER: == sanity test 102i: lgetxattr test on symbolic link ====================================================================== 06:08:59 (1778926139) [ 3291.365964] Lustre: DEBUG MARKER: == sanity test 102j: non-root tar restore stripe info from tarfile, not keep osts ============================================================= 06:09:08 (1778926148) [ 3314.943569] Lustre: DEBUG MARKER: == sanity test 102k: setfattr without parameter of value shouldn't cause a crash ========================================================== 06:09:31 (1778926171) [ 3325.175894] Lustre: DEBUG MARKER: == sanity test 102l: listxattr size test ============================================================================================ 06:09:41 (1778926181) [ 3335.295489] Lustre: DEBUG MARKER: == sanity test 102m: Ensure listxattr fails on small bufffer ================================================================== 06:09:51 (1778926191) [ 3344.809798] Lustre: DEBUG MARKER: == sanity test 102n: silently ignore setxattr on internal trusted xattrs ========================================================== 06:10:01 (1778926201) [ 3356.104915] Lustre: DEBUG MARKER: == sanity test 102p: check setxattr(2) correctly fails without permission ========================================================== 06:10:12 (1778926212) [ 3364.976402] Lustre: DEBUG MARKER: == sanity test 102q: flistxattr should not return trusted.link EAs for orphans ========================================================== 06:10:21 (1778926221) [ 3375.215514] Lustre: DEBUG MARKER: == sanity test 102r: set EAs with empty values =========== 06:10:31 (1778926231) [ 3385.245275] Lustre: DEBUG MARKER: == sanity test 102s: getting nonexistent xattrs should fail ========================================================== 06:10:41 (1778926241) [ 3394.895214] Lustre: DEBUG MARKER: == sanity test 102t: zero length xattr values handled correctly ========================================================== 06:10:52 (1778926252) [ 3404.191879] Lustre: DEBUG MARKER: == sanity test 103a: acl test ============================ 06:11:01 (1778926261) [ 3750.599475] Lustre: DEBUG MARKER: == sanity test 103b: umask lfs setstripe ================= 06:16:47 (1778926607) [ 3951.929473] Lustre: DEBUG MARKER: == sanity test 103c: 'cp -rp' won't set empty acl ======== 06:20:08 (1778926808) [ 3960.684098] Lustre: DEBUG MARKER: == sanity test 103e: inheritance of big amount of default ACLs ========================================================== 06:20:17 (1778926817) [ 3992.860021] Lustre: DEBUG MARKER: == sanity test 103f: changelog doesn't interfere with default ACLs buffers ========================================================== 06:20:47 (1778926847) [ 3996.947799] Lustre: lustre-MDD0000: changelog on [ 4004.208606] Lustre: lustre-MDD0000: changelog off [ 4007.268748] Lustre: DEBUG MARKER: == sanity test 104a: lfs df [-ih] [path] test =================================================================================== 06:21:04 (1778926864) [ 4007.813519] Lustre: lustre-OST0000: Client 005694fe-ec2a-4216-88e6-7ba4f49cf1ab (at 192.168.204.1@tcp) reconnecting [ 4011.727910] Lustre: DEBUG MARKER: oleg401-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff8e8105c16800.ost_server_uuid 50 [ 4013.423777] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8e8105c16800.ost_server_uuid in FULL state after 0 sec [ 4021.022723] Lustre: DEBUG MARKER: == sanity test 104b: runas -u 500 -g 500 lfs check servers test ============================================================================== 06:21:18 (1778926878) [ 4027.867863] Lustre: DEBUG MARKER: == sanity test 104c: Verify df vs lfs_df stays same after recordsize change ========================================================== 06:21:24 (1778926884) [ 4051.786195] Lustre: DEBUG MARKER: == sanity test 104d: runas -u 500 -g 500 lctl dl test ==== 06:21:48 (1778926908) [ 4059.795437] Lustre: DEBUG MARKER: == sanity test 105a: flock when mounted without -o flock test ================================================================== 06:21:56 (1778926916) [ 4066.318385] Lustre: DEBUG MARKER: == sanity test 105b: fcntl when mounted without -o flock test ================================================================== 06:22:03 (1778926923) [ 4073.187750] Lustre: DEBUG MARKER: == sanity test 105c: lockf when mounted without -o flock test ========================================================== 06:22:10 (1778926930) [ 4080.036968] Lustre: DEBUG MARKER: == sanity test 105d: flock race (should not freeze) ================================================================== 06:22:17 (1778926937) [ 4098.455472] Lustre: DEBUG MARKER: == sanity test 105e: Two conflicting flocks from same process ========================================================== 06:22:35 (1778926955) [ 4105.098667] Lustre: DEBUG MARKER: == sanity test 105f: Enqueue same range flocks =========== 06:22:42 (1778926962) [ 4112.415467] Lustre: DEBUG MARKER: == sanity test 105g: ldlm_lock_debug stack test ========== 06:22:49 (1778926969) [ 4120.249486] Lustre: DEBUG MARKER: == sanity test 105h: Flock functional verify ============= 06:22:57 (1778926977) [ 4126.969892] Lustre: DEBUG MARKER: == sanity test 105i: Flock deadlock verify =============== 06:23:04 (1778926984) [ 4138.089560] Lustre: DEBUG MARKER: == sanity test 106: attempt exec of dir followed by chown of that dir ========================================================== 06:23:15 (1778926995) [ 4144.092319] Lustre: DEBUG MARKER: == sanity test 107: Coredump on SIG ====================== 06:23:21 (1778927001) [ 4152.100095] Lustre: DEBUG MARKER: == sanity test 110: filename length checking ============= 06:23:29 (1778927009) [ 4158.176247] Lustre: DEBUG MARKER: == sanity test 116a: stripe QOS: free space balance ============================================================================= 06:23:35 (1778927015) [ 4396.040347] Lustre: DEBUG MARKER: == sanity test 116b: QoS shouldn't LBUG if not enough OSTs found on the 2nd pass ========================================================== 06:27:33 (1778927253) [ 4399.159850] Lustre: *** cfs_fail_loc=147, val=0*** [ 4399.670324] Lustre: *** cfs_fail_loc=147, val=0*** [ 4399.675895] Lustre: Skipped 23 previous similar messages [ 4409.084264] Lustre: DEBUG MARKER: == sanity test 117: verify osd extend ==================== 06:27:46 (1778927266) [ 4416.456735] Lustre: DEBUG MARKER: == sanity test 118a: verify O_SYNC works ================= 06:27:53 (1778927273) [ 4423.837462] Lustre: DEBUG MARKER: == sanity test 118b: Reclaim dirty pages on fatal error ==================================================================== 06:28:01 (1778927281) [ 4426.275707] Lustre: *** cfs_fail_loc=217, val=0*** [ 4426.278522] Lustre: Skipped 3 previous similar messages [ 4433.143246] Lustre: DEBUG MARKER: SKIP: sanity test_118c skipping ALWAYS excluded test 118c [ 4434.710947] Lustre: DEBUG MARKER: SKIP: sanity test_118d skipping ALWAYS excluded test 118d [ 4436.470990] Lustre: DEBUG MARKER: == sanity test 118f: Simulate unrecoverable OSC side error ==================================================================== 06:28:13 (1778927293) [ 4443.777334] Lustre: DEBUG MARKER: == sanity test 118g: Don't stay in wait if we got local -ENOMEM ==================================================================== 06:28:21 (1778927301) [ 4450.849784] Lustre: DEBUG MARKER: == sanity test 118h: Verify timeout in handling recoverables errors ==================================================================== 06:28:28 (1778927308) [ 4452.585610] Lustre: *** cfs_fail_loc=20e, val=0*** [ 4453.644096] Lustre: *** cfs_fail_loc=20e, val=0*** [ 4455.819226] Lustre: *** cfs_fail_loc=20e, val=0*** [ 4458.889815] Lustre: *** cfs_fail_loc=20e, val=0*** [ 4462.921383] Lustre: *** cfs_fail_loc=20e, val=0*** [ 4470.307626] Lustre: DEBUG MARKER: == sanity test 118i: Fix error before timeout in recoverable error ==================================================================== 06:28:47 (1778927327) [ 4472.591531] Lustre: *** cfs_fail_loc=20e, val=0*** [ 4488.503369] Lustre: DEBUG MARKER: == sanity test 118j: Simulate unrecoverable OST side error ==================================================================== 06:29:05 (1778927345) [ 4490.016651] Lustre: *** cfs_fail_loc=220, val=0*** [ 4490.018698] Lustre: Skipped 3 previous similar messages [ 4496.614573] Lustre: DEBUG MARKER: == sanity test 118k: bio alloc -ENOMEM and IO TERM handling =================================================================== 06:29:14 (1778927354) [ 4515.961511] Lustre: DEBUG MARKER: == sanity test 118l: fsync dir =========================== 06:29:33 (1778927373) [ 4521.739397] Lustre: DEBUG MARKER: == sanity test 118m: fdatasync dir ======================= 06:29:39 (1778927379) [ 4528.969220] Lustre: DEBUG MARKER: == sanity test 118n: statfs() sends OST_STATFS requests in parallel ========================================================== 06:29:46 (1778927386) [ 4539.658706] Lustre: DEBUG MARKER: == sanity test 119a: Short directIO read must return actual read amount ========================================================== 06:29:57 (1778927397) [ 4545.959693] Lustre: DEBUG MARKER: == sanity test 119b: Sparse directIO read must return actual read amount ========================================================== 06:30:03 (1778927403) [ 4552.242682] Lustre: DEBUG MARKER: == sanity test 119c: Testing for direct read hitting hole ========================================================== 06:30:09 (1778927409) [ 4558.461483] Lustre: DEBUG MARKER: == sanity test 119e: Basic tests of dio read and write at various sizes ========================================================== 06:30:15 (1778927415) [ 4594.202520] Lustre: DEBUG MARKER: == sanity test 119f: dio vs dio race ===================== 06:30:51 (1778927451) [ 4626.947379] Lustre: DEBUG MARKER: == sanity test 119g: dio vs buffered I/O race ============ 06:31:24 (1778927484) [ 4655.467545] Lustre: DEBUG MARKER: == sanity test 119h: basic tests of memory unaligned dio ========================================================== 06:31:53 (1778927513) [ 4674.876749] Lustre: DEBUG MARKER: SKIP: sanity test_119i skipping ALWAYS excluded test 119i [ 4676.263979] Lustre: DEBUG MARKER: == sanity test 119j: basic tests of hybrid IO switching == 06:32:13 (1778927533) [ 4684.038468] Lustre: DEBUG MARKER: == sanity test 119k: hybrid IO counting with stats and disabling ========================================================== 06:32:21 (1778927541) [ 4695.429539] Lustre: DEBUG MARKER: == sanity test 119m: Test DIO readv/writev: exercise iter duplication ========================================================== 06:32:33 (1778927553) [ 4700.774238] Lustre: DEBUG MARKER: == sanity test 119n: Test Unaligned DIO readv() and writev() with unpatched ZFS ========================================================== 06:32:38 (1778927558) [ 4702.142874] Lustre: DEBUG MARKER: SKIP: sanity test_119n zfs server without 'unaligned_dio' support [ 4703.786397] Lustre: DEBUG MARKER: == sanity test 119o: Test Unaligned DIO readv() and writev() with unpatched servers ========================================================== 06:32:41 (1778927561) [ 4704.969848] Lustre: DEBUG MARKER: SKIP: sanity test_119o need ldiskfs without 'unaligned_dio' support [ 4706.348637] Lustre: DEBUG MARKER: == sanity test 119p: Test Unaligned DIO readv() and writev() with patched servers ========================================================== 06:32:43 (1778927563) [ 4712.219193] Lustre: DEBUG MARKER: == sanity test 119q: Test patchded Unaligned DIO readv() and writev() ========================================================== 06:32:49 (1778927569) [ 4724.548656] Lustre: DEBUG MARKER: == sanity test 120a: Early Lock Cancel: mkdir test ======= 06:33:01 (1778927581) [ 4731.680471] Lustre: DEBUG MARKER: == sanity test 120b: Early Lock Cancel: create test ====== 06:33:09 (1778927589) [ 4737.603563] Lustre: DEBUG MARKER: == sanity test 120c: Early Lock Cancel: link test ======== 06:33:15 (1778927595) [ 4744.510344] Lustre: DEBUG MARKER: == sanity test 120d: Early Lock Cancel: setattr test ===== 06:33:22 (1778927602) [ 4751.206944] Lustre: DEBUG MARKER: == sanity test 120e: Early Lock Cancel: unlink test ====== 06:33:28 (1778927608) [ 4764.253443] Lustre: DEBUG MARKER: == sanity test 120f: Early Lock Cancel: rename test ====== 06:33:42 (1778927622) [ 4777.914641] Lustre: DEBUG MARKER: == sanity test 120g: Early Lock Cancel: performance test ========================================================== 06:33:55 (1778927635) [ 5091.615113] Lustre: DEBUG MARKER: == sanity test 121: read cancel race ===================== 06:39:09 (1778927949) [ 5096.303739] Lustre: DEBUG MARKER: == sanity test 123aa: verify statahead work ============== 06:39:14 (1778927954) [ 5103.659530] Lustre: DEBUG MARKER: 'ls -l' 100 files without statahead: 2 sec [ 5105.686112] Lustre: DEBUG MARKER: 'ls -l' 100 files with statahead: 1 sec [ 5134.386132] Lustre: DEBUG MARKER: 'ls -l' 1000 files without statahead: 16 sec [ 5139.971128] Lustre: DEBUG MARKER: 'ls -l' 1000 files with statahead: 3 sec [ 5140.921400] Lustre: DEBUG MARKER: 'ls -l' done [ 5154.792864] Lustre: DEBUG MARKER: unlink + rm -r /mnt/lustre/d123aa.sanity: 13 seconds [ 5161.810228] Lustre: DEBUG MARKER: == sanity test 123ab: verify statahead work by using statx ========================================================== 06:40:19 (1778928019) [ 5167.857736] Lustre: DEBUG MARKER: 'statx -l' 100 files without statahead: 1 sec [ 5169.432149] Lustre: DEBUG MARKER: 'statx -l' 100 files with statahead: 1 sec [ 5198.294990] Lustre: DEBUG MARKER: 'statx -l' 1000 files without statahead: 16 sec [ 5203.058791] Lustre: DEBUG MARKER: 'statx -l' 1000 files with statahead: 3 sec [ 5204.022233] Lustre: DEBUG MARKER: 'statx -l' done [ 5217.716696] Lustre: DEBUG MARKER: unlink + rm -r /mnt/lustre/d123ab.sanity: 13 seconds [ 5224.959849] Lustre: DEBUG MARKER: == sanity test 123ac: verify statahead work by using statx without glimpse RPCs ========================================================== 06:41:22 (1778928082) [ 5230.257173] Lustre: DEBUG MARKER: 'statx -c 1 [ 5231.667222] Lustre: DEBUG MARKER: 'statx -c 1 [ 5252.983140] Lustre: DEBUG MARKER: 'statx -c 1 [ 5256.898427] Lustre: DEBUG MARKER: 'statx -c 1 [ 5257.936847] Lustre: DEBUG MARKER: 'statx -c 1 [ 5270.051114] Lustre: DEBUG MARKER: unlink + rm -r /mnt/lustre/d123ac.sanity: 11 seconds [ 5274.057855] Lustre: DEBUG MARKER: 'statx --cached=always -D' 100 files without statahead: 0 sec [ 5275.226468] Lustre: DEBUG MARKER: 'statx --cached=always -D' 100 files with statahead: 1 sec [ 5286.858314] Lustre: DEBUG MARKER: 'statx --cached=always -D' 1000 files without statahead: 0 sec [ 5287.923753] Lustre: DEBUG MARKER: 'statx --cached=always -D' 1000 files with statahead: 0 sec [ 5367.323925] Lustre: DEBUG MARKER: 'statx --cached=always -D' 10000 files without statahead: 1 sec [ 5368.564753] Lustre: DEBUG MARKER: 'statx --cached=always -D' 10000 files with statahead: 0 sec [ 6052.493198] Lustre: DEBUG MARKER: 'statx --cached=always -D' 100000 files without statahead: 2 sec [ 6055.110061] Lustre: DEBUG MARKER: 'statx --cached=always -D' 100000 files with statahead: 2 sec [ 6055.763699] Lustre: DEBUG MARKER: 'statx --cached=always -D' done [ 7347.293806] Lustre: DEBUG MARKER: unlink + rm -r /mnt/lustre/d123ac.sanity: 1291 seconds [ 7352.417832] Lustre: DEBUG MARKER: == sanity test 123ad: Verify batching statahead works correctly ========================================================== 07:16:50 (1778930210) [ 7355.417355] Lustre: DEBUG MARKER: 'ls -l' 100 files without statahead: 1 sec [ 7356.529481] Lustre: DEBUG MARKER: 'ls -l' 100 files with statahead: 0 sec [ 7366.863761] Lustre: DEBUG MARKER: 'ls -l' 1000 files without statahead: 7 sec [ 7371.780621] Lustre: DEBUG MARKER: 'ls -l' 1000 files with statahead: 4 sec [ 7372.337178] Lustre: DEBUG MARKER: 'ls -l' done [ 7377.493986] Lustre: DEBUG MARKER: unlink + rm -r /mnt/lustre/d123ad.sanity: 4 seconds [ 7560.255234] Lustre: DEBUG MARKER: 'ls -l' 100 files without statahead: 1 sec [ 7561.256331] Lustre: DEBUG MARKER: 'ls -l' 100 files with statahead: 0 sec [ 7571.195657] Lustre: DEBUG MARKER: 'ls -l' 1000 files without statahead: 6 sec [ 7575.705156] Lustre: DEBUG MARKER: 'ls -l' 1000 files with statahead: 3 sec [ 7576.273704] Lustre: DEBUG MARKER: 'ls -l' done [ 7582.375241] Lustre: DEBUG MARKER: unlink + rm -r /mnt/lustre/d123ad.sanity: 5 seconds [ 7739.035845] Lustre: DEBUG MARKER: == sanity test 123b: not panic with network error in statahead enqueue (bug 15027) ========================================================== 07:23:17 (1778930597) [ 7740.921955] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x240000400 to 0x240000401 [ 7740.949396] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x280000400 to 0x280000401 [ 7745.965115] Lustre: DEBUG MARKER: ls done [ 7753.499125] Lustre: DEBUG MARKER: == sanity test 123c: Can not initialize inode warning on DNE statahead ========================================================== 07:23:31 (1778930611) [ 7754.019903] Lustre: DEBUG MARKER: SKIP: sanity test_123c needs >= 2 MDTs [ 7754.657649] Lustre: DEBUG MARKER: == sanity test 123d: Statahead on striped directories works correctly ========================================================== 07:23:32 (1778930612) [ 7759.673157] Lustre: DEBUG MARKER: == sanity test 123e: statahead with large wide striping == 07:23:37 (1778930617) [ 7803.013186] Lustre: 52506:0:(mdt_handler.c:4705:mdt_unpack_req_pack_rep()) lustre-MDT0000: cannot pack response: rc = -75 [ 7898.468553] Lustre: DEBUG MARKER: == sanity test 123f: Retry mechanism with large wide striping files ========================================================== 07:25:55 (1778930755) [ 7990.429169] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x240000401 to 0x240000402 [ 7991.274387] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x280000401 to 0x280000402 [ 8505.807258] Lustre: DEBUG MARKER: == sanity test 123g: Test for stat-ahead advise ========== 07:36:02 (1778931362) [ 8515.132972] Lustre: DEBUG MARKER: == sanity test 123h: Verify statahead work with the fname pattern via du ========================================================== 07:36:13 (1778931373) [ 8981.168514] Lustre: DEBUG MARKER: == sanity test 123i: Verify statahead work with the fname indexing pattern ========================================================== 07:43:59 (1778931839) [ 9065.211469] Lustre: DEBUG MARKER: == sanity test 123j: -ENOENT error from batched statahead be handled correctly ========================================================== 07:45:23 (1778931923) [ 9066.014741] Lustre: DEBUG MARKER: SKIP: sanity test_123j needs >= 2 MDTs [ 9066.900563] Lustre: DEBUG MARKER: == sanity test 123k: Verify statahead work with mdtest shared stat() mode ========================================================== 07:45:24 (1778931924) [ 9067.761821] Lustre: DEBUG MARKER: SKIP: sanity test_123k mdtest not found [ 9068.634703] Lustre: DEBUG MARKER: == sanity test 123l: Avoid panic when revalidate a local cached entry ========================================================== 07:45:26 (1778931926) [ 9140.684922] Lustre: DEBUG MARKER: == sanity test 124a: lru resize ================================================================================================= 07:46:38 (1778931998) [ 9141.252309] Lustre: DEBUG MARKER: create 2000 files at /mnt/lustre/d124a.sanity [ 9153.117728] Lustre: DEBUG MARKER: NSDIR=ldlm.namespaces.lustre-MDT0000-mdc-ffff8e81069b2800 [ 9153.600442] Lustre: DEBUG MARKER: NS=ldlm.namespaces.lustre-MDT0000-mdc-ffff8e81069b2800 [ 9154.106474] Lustre: DEBUG MARKER: LRU=2003 [ 9154.614862] Lustre: DEBUG MARKER: LIMIT=61549 [ 9155.122540] Lustre: DEBUG MARKER: LVF=3687400 [ 9155.624348] Lustre: DEBUG MARKER: OLD_LVF=100 [ 9156.121399] Lustre: DEBUG MARKER: Sleep 50 sec [ 9206.909311] Lustre: DEBUG MARKER: Dropped 848 locks in 50s [ 9207.396173] Lustre: DEBUG MARKER: unlink 2000 files at /mnt/lustre/d124a.sanity [ 9214.145645] Lustre: DEBUG MARKER: == sanity test 124b: lru resize (performance test) ================================================================================= 07:47:52 (1778932072) [ 9237.011734] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x240000402 to 0x240000403 [ 9237.021697] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x280000402 to 0x280000403 [ 9247.457390] Lustre: DEBUG MARKER: doing ls -la /mnt/lustre/d124b.sanity/disable_lru_resize 3 times [ 9334.997233] Lustre: DEBUG MARKER: ls -la time: 86 seconds [ 9335.733922] Lustre: DEBUG MARKER: lru_size = 400 [ 9385.898314] Lustre: DEBUG MARKER: doing ls -la /mnt/lustre/d124b.sanity/enable_lru_resize 3 times [ 9433.065200] Lustre: DEBUG MARKER: ls -la time: 44 seconds [ 9433.782859] Lustre: DEBUG MARKER: lru_size = 8005 [ 9434.405395] Lustre: DEBUG MARKER: ls -la is 48% faster with lru resize enabled [ 9453.459620] Lustre: DEBUG MARKER: == sanity test 124c: LRUR cancel very aged locks ========= 07:51:51 (1778932311) [ 9483.731363] Lustre: DEBUG MARKER: == sanity test 124d: cancel very aged locks if lru-resize disabled ========================================================== 07:52:21 (1778932341) [ 9509.392874] Lustre: DEBUG MARKER: == sanity test 124e: LFRU keep priv locks from eviction == 07:52:47 (1778932367) [ 9531.281679] Lustre: DEBUG MARKER: == sanity test 124f: LFRU priv threshold inc/dec adjustment ========================================================== 07:53:09 (1778932389) [ 9569.372494] Lustre: DEBUG MARKER: == sanity test 124g: LFRU performance test =============== 07:53:47 (1778932427) [ 9817.843596] Lustre: DEBUG MARKER: == sanity test 125: don't return EPROTO when a dir has a non-default striping and ACLs ========================================================== 07:57:55 (1778932675) [ 9820.650090] Lustre: DEBUG MARKER: == sanity test 126: check that the fsgid provided by the client is taken into account ========================================================== 07:57:58 (1778932678) [ 9823.327739] Lustre: DEBUG MARKER: == sanity test 127a: verify the client stats are sane ==== 07:58:01 (1778932681) [ 9826.993579] Lustre: DEBUG MARKER: == sanity test 127b: verify the llite client stats are sane ========================================================== 07:58:05 (1778932685) [ 9830.377787] Lustre: DEBUG MARKER: == sanity test 127c: test llite extent stats with regular [ 9848.719228] Lustre: DEBUG MARKER: == sanity test 127d: OSC RPC latency histograms for read and write latency ========================================================== 07:58:26 (1778932706) [ 9853.553195] Lustre: DEBUG MARKER: == sanity test 127e: client IO latency histograms by size ========================================================== 07:58:31 (1778932711) [ 9864.819744] Lustre: DEBUG MARKER: == sanity test 127f: OST IO latency histograms by size === 07:58:42 (1778932722) [ 9865.618882] Lustre: DEBUG MARKER: SKIP: sanity test_127f ldiskfs only [ 9866.509643] Lustre: DEBUG MARKER: == sanity test 128: interactive lfs for 2 consecutive find's ========================================================== 07:58:44 (1778932724) [ 9869.746534] Lustre: DEBUG MARKER: == sanity test 129: test directory size limit ================================================================================== 07:58:47 (1778932727) [ 9870.528741] Lustre: DEBUG MARKER: SKIP: sanity test_129 ldiskfs only test [ 9871.402921] Lustre: DEBUG MARKER: == sanity test 130a: FIEMAP (1-stripe file) ============== 07:58:49 (1778932729) [ 9872.329891] Lustre: DEBUG MARKER: SKIP: sanity test_130a LU-1941: FIEMAP unimplemented on ZFS [ 9873.166831] Lustre: DEBUG MARKER: SKIP: sanity test_130b skipping ALWAYS excluded test 130b [ 9873.917413] Lustre: DEBUG MARKER: SKIP: sanity test_130c skipping ALWAYS excluded test 130c [ 9874.642670] Lustre: DEBUG MARKER: SKIP: sanity test_130d skipping ALWAYS excluded test 130d [ 9875.307563] Lustre: DEBUG MARKER: SKIP: sanity test_130e skipping ALWAYS excluded test 130e [ 9876.130166] Lustre: DEBUG MARKER: SKIP: sanity test_130f skipping ALWAYS excluded test 130f [ 9876.946812] Lustre: DEBUG MARKER: SKIP: sanity test_130g skipping ALWAYS excluded test 130g [ 9877.750753] Lustre: DEBUG MARKER: == sanity test 130h: FIEMAP deadlock ===================== 07:58:55 (1778932735) [ 9887.254739] Lustre: DEBUG MARKER: == sanity test 130i: FIEMAP (DoM file) =================== 07:59:05 (1778932745) [ 9888.029418] Lustre: DEBUG MARKER: SKIP: sanity test_130i LU-1941: FIEMAP unimplemented on ZFS [ 9888.910814] Lustre: DEBUG MARKER: == sanity test 131a: test iov's crossing stripe boundary for writev/readv ========================================================== 07:59:06 (1778932746) [ 9892.236083] Lustre: DEBUG MARKER: == sanity test 131b: test append writev ================== 07:59:10 (1778932750) [ 9895.903371] Lustre: DEBUG MARKER: == sanity test 131c: test read/write on file w/o objects ========================================================== 07:59:13 (1778932753) [ 9899.108401] Lustre: DEBUG MARKER: == sanity test 131d: test short read ===================== 07:59:17 (1778932757) [ 9902.180816] Lustre: DEBUG MARKER: == sanity test 131e: test read hitting hole ============== 07:59:20 (1778932760) [ 9905.453941] Lustre: DEBUG MARKER: == sanity test 133a: Verifying MDT stats ================================================================================================== 07:59:23 (1778932763) [ 9915.418887] Lustre: DEBUG MARKER: == sanity test 133b: Verifying extra MDT stats ============================================================================================ 07:59:33 (1778932773) [ 9928.134281] Lustre: DEBUG MARKER: == sanity test 133c: Verifying OST stats ================================================================================================== 07:59:46 (1778932786) [ 9965.067831] Lustre: DEBUG MARKER: == sanity test 133d: Verifying rename_stats ================================================================================================== 08:00:23 (1778932823) [ 9981.274332] Lustre: DEBUG MARKER: == sanity test 133e: Verifying OST read_bytes write_bytes nid stats =========================================================================== 08:00:39 (1778932839) [ 9986.984772] Lustre: DEBUG MARKER: == sanity test 133f: Check reads/writes of client lustre proc files with bad area io ========================================================== 08:00:45 (1778932845) [ 9996.771196] 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 [ 9996.772078] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 9996.779452] Lustre: Skipped 1 previous similar message [ 9999.220451] Lustre: server umount lustre-MDT0000 complete [10001.125355] LustreError: 71105:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1778932859 with bad export cookie 5118731840670267665 [10001.129307] LustreError: MGC192.168.204.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10001.132554] LustreError: 71105:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [10001.211092] Lustre: server umount lustre-OST0000 complete [10003.256095] Lustre: server umount lustre-OST0001 complete [10008.282978] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing unload_modules_local [10009.725256] Key type lgssc unregistered [10009.865834] LNet: 97829:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10009.871308] LNetError: 97829:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [10009.883565] LNet: Removed LNI 192.168.204.101@tcp [10010.285164] Key type .llcrypt unregistered [10010.287669] Key type ._llcrypt unregistered [10017.881961] Key type ._llcrypt registered [10017.884112] Key type .llcrypt registered [10017.950842] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_modules_local [10018.313890] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [10018.350896] alg: No test for adler32 (adler32-zlib) [10019.209836] Lustre: Lustre: Build Version: 2.17.53_3_g0d061c0 [10019.315908] LNet: Added LNI 192.168.204.101@tcp [8/256/0/180] [10020.912250] Key type lgssc registered [10021.493878] Lustre: Echo OBD driver; http://www.lustre.org/ [10027.626164] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_modules_local [10030.857663] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [10032.128674] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10033.889923] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [10035.275461] Lustre: 99932:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10037.552372] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [10040.078262] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [10041.645827] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000403:7411 to 0x240000403:7681) [10043.301353] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [10045.234136] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [10048.503495] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000403:7403 to 0x280000403:7681) [10050.341687] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10051.998592] Lustre: 101713:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10056.696758] Lustre: DEBUG MARKER: == sanity test 133g: Check reads/writes of server lustre proc files with bad area io ========================================================== 08:01:54 (1778932914) [10059.386381] LNet: 102204:0:(debug.c:370:cfs_str2mask()) unknown mask ''. [10059.386381] mask usage: [+|-] ... [10059.575884] Lustre: DEBUG MARKER:  [10059.577637] Lustre: DEBUG MARKER:  [10069.271656] LNet: 103351:0:(debug.c:370:cfs_str2mask()) unknown mask ''. [10069.271656] mask usage: [+|-] ... [10069.274846] LNet: 103351:0:(debug.c:370:cfs_str2mask()) Skipped 8 previous similar messages [10069.510799] Lustre: DEBUG MARKER:  [10069.512720] Lustre: DEBUG MARKER:  [10079.689522] Lustre: server umount lustre-MDT0000 complete [10081.411322] LustreError: 101715:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1778932940 with bad export cookie 4328014260805814006 [10081.419294] LustreError: MGC192.168.204.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10092.046912] Lustre: server umount lustre-OST0000 complete [10104.251337] Lustre: server umount lustre-OST0001 complete [10109.626989] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing unload_modules_local [10111.070580] Key type lgssc unregistered [10111.217666] LNet: 105404:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10111.222762] LNetError: 105404:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [10111.234649] LNet: Removed LNI 192.168.204.101@tcp [10111.600164] Key type .llcrypt unregistered [10111.602693] Key type ._llcrypt unregistered [10117.483727] Key type ._llcrypt registered [10117.485485] Key type .llcrypt registered [10117.548630] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_modules_local [10117.986924] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [10117.995469] alg: No test for adler32 (adler32-zlib) [10118.858658] Lustre: Lustre: Build Version: 2.17.53_3_g0d061c0 [10118.961786] LNet: Added LNI 192.168.204.101@tcp [8/256/0/180] [10120.552152] Key type lgssc registered [10121.061497] Lustre: Echo OBD driver; http://www.lustre.org/ [10127.022903] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_modules_local [10130.032639] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [10131.339062] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10132.863621] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [10134.254727] Lustre: 107507:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10136.307244] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [10138.589886] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [10141.144652] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [10142.200767] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000403:7403 to 0x280000403:7713) [10142.201083] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000403:7411 to 0x240000403:7713) [10143.595296] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [10148.738684] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10150.347329] Lustre: 109281:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10153.486973] Lustre: DEBUG MARKER: == sanity test 133h: Proc files should end with newlines ========================================================== 08:03:31 (1778933011) [10602.199337] Lustre: DEBUG MARKER: == sanity test 134a: Server reclaims locks when reaching lock_reclaim_threshold ========================================================== 08:11:00 (1778933460) [10608.733883] Lustre: *** cfs_fail_loc=327, val=500*** [10609.271772] Lustre: *** cfs_fail_loc=327, val=500*** [10609.273065] Lustre: Skipped 512 previous similar messages [10628.678418] Lustre: DEBUG MARKER: == sanity test 134b: Server rejects lock request when reaching lock_limit_mb ========================================================== 08:11:26 (1778933486) [10631.771630] Lustre: *** cfs_fail_loc=328, val=500*** [10633.168951] Lustre: 109047:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) @@@ Too many granted locks, reject current enqueue request and let the client retry later req@ffff8f53f5978e00 x1865346421238400/t0(0) o101->0a3b7535-5203-4bfc-b981-e67584235c9d@192.168.204.1@tcp:238/0 lens 648/0 e 0 to 0 dl 1778933503 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [10634.253943] Lustre: *** cfs_fail_loc=328, val=500*** [10634.256865] Lustre: Skipped 501 previous similar messages [10634.259799] Lustre: 107092:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) @@@ Too many granted locks, reject current enqueue request and let the client retry later req@ffff8f53fc1f0000 x1865346421239168/t0(0) o101->0a3b7535-5203-4bfc-b981-e67584235c9d@192.168.204.1@tcp:239/0 lens 648/0 e 0 to 0 dl 1778933504 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [10635.341930] Lustre: 107852:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) @@@ Too many granted locks, reject current enqueue request and let the client retry later req@ffff8f53f597b480 x1865346421239936/t0(0) o101->0a3b7535-5203-4bfc-b981-e67584235c9d@192.168.204.1@tcp:240/0 lens 648/0 e 0 to 0 dl 1778933505 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [10637.453353] Lustre: 107092:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) @@@ Too many granted locks, reject current enqueue request and let the client retry later req@ffff8f53e5f11500 x1865346421241728/t0(0) o101->0a3b7535-5203-4bfc-b981-e67584235c9d@192.168.204.1@tcp:242/0 lens 648/0 e 0 to 0 dl 1778933507 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [10637.471768] Lustre: 107092:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) Skipped 1 previous similar message [10638.542219] Lustre: *** cfs_fail_loc=328, val=500*** [10638.545021] Lustre: Skipped 3 previous similar messages [10641.613972] Lustre: 109047:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) @@@ Too many granted locks, reject current enqueue request and let the client retry later req@ffff8f53e5f12a00 x1865346421244800/t0(0) o101->0a3b7535-5203-4bfc-b981-e67584235c9d@192.168.204.1@tcp:246/0 lens 648/0 e 0 to 0 dl 1778933511 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [10641.632098] Lustre: 109047:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) Skipped 3 previous similar messages [10646.798469] Lustre: *** cfs_fail_loc=328, val=500*** [10646.801461] Lustre: Skipped 7 previous similar messages [10649.870641] Lustre: 107093:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) @@@ Too many granted locks, reject current enqueue request and let the client retry later req@ffff8f53c5054a80 x1865346421251456/t0(0) o101->0a3b7535-5203-4bfc-b981-e67584235c9d@192.168.204.1@tcp:254/0 lens 648/0 e 0 to 0 dl 1778933519 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [10649.888377] Lustre: 107093:0:(ldlm_lockd.c:1326:ldlm_handle_enqueue()) Skipped 7 previous similar messages [10652.179947] LustreError: 162489:0:(ldlm_lockd.c:3240:lock_reclaim_threshold_mb_store()) Failed to set lock_reclaim_threshold_mb, rc = -22. [10659.077969] Lustre: DEBUG MARKER: SKIP: sanity test_135 skipping SLOW test 135 [10659.930355] Lustre: DEBUG MARKER: SKIP: sanity test_136 skipping SLOW test 136 [10660.908503] Lustre: DEBUG MARKER: == sanity test 140: Check reasonable stack depth (shouldn't LBUG) ============================================================== 08:11:58 (1778933518) [10679.790207] Lustre: DEBUG MARKER: == sanity test 150a: truncate/append tests =============== 08:12:17 (1778933537) [10717.933306] Lustre: DEBUG MARKER: == sanity test 150b: Verify fallocate (prealloc) functionality ========================================================== 08:12:56 (1778933576) [10718.699616] Lustre: DEBUG MARKER: SKIP: sanity test_150b need >= 2.13.57 and ldiskfs for fallocate [10719.588963] Lustre: DEBUG MARKER: == sanity test 150bb: Verify fallocate modes both zero space ========================================================== 08:12:57 (1778933577) [10720.301077] Lustre: DEBUG MARKER: SKIP: sanity test_150bb need >= 2.13.57 and ldiskfs for fallocate [10721.088730] Lustre: DEBUG MARKER: == sanity test 150c: Verify fallocate Size and Blocks ==== 08:12:59 (1778933579) [10721.589615] Lustre: DEBUG MARKER: SKIP: sanity test_150c need >= 2.13.57 and ldiskfs for fallocate [10722.312856] Lustre: DEBUG MARKER: == sanity test 150d: Verify fallocate Size and Blocks - Non zero start ========================================================== 08:13:00 (1778933580) [10723.045922] Lustre: DEBUG MARKER: SKIP: sanity test_150d need >= 2.13.57 and ldiskfs for fallocate [10723.775791] Lustre: DEBUG MARKER: == sanity test 150e: Verify 60% of available OST space consumed by fallocate ========================================================== 08:13:01 (1778933581) [10724.567947] Lustre: DEBUG MARKER: SKIP: sanity test_150e need >= 2.13.57 and ldiskfs for fallocate [10725.349602] Lustre: DEBUG MARKER: == sanity test 150f: Verify fallocate punch functionality ========================================================== 08:13:03 (1778933583) [10726.088725] Lustre: DEBUG MARKER: SKIP: sanity test_150f LU-14160: punch mode is not implemented on OSD ZFS [10726.922765] Lustre: DEBUG MARKER: == sanity test 150g: Verify fallocate punch on large range ========================================================== 08:13:04 (1778933584) [10727.673887] Lustre: DEBUG MARKER: SKIP: sanity test_150g LU-14160: punch mode is not implemented on OSD ZFS [10728.536575] Lustre: DEBUG MARKER: == sanity test 150h: Verify extend fallocate updates the file size ========================================================== 08:13:06 (1778933586) [10729.299796] Lustre: DEBUG MARKER: SKIP: sanity test_150h need >= 2.13.57 and ldiskfs for fallocate [10730.144985] Lustre: DEBUG MARKER: == sanity test 150ia: Verify fallocate zero-range ZERO functionality ========================================================== 08:13:08 (1778933588) [10730.615823] Lustre: DEBUG MARKER: SKIP: sanity test_150ia zero-range mode is not implemented on OSD ZFS [10731.327879] Lustre: DEBUG MARKER: == sanity test 150ib: Verify fallocate zero-range PREALLOC functionality ========================================================== 08:13:09 (1778933589) [10731.997403] Lustre: DEBUG MARKER: SKIP: sanity test_150ib zero-range mode is not implemented on OSD ZFS [10732.871389] Lustre: DEBUG MARKER: == sanity test 150ic: Verify fallocate LARGE zero PREALLOC functionality ========================================================== 08:13:10 (1778933590) [10733.678873] Lustre: DEBUG MARKER: SKIP: sanity test_150ic zero-range mode is not implemented on OSD ZFS [10734.538923] Lustre: DEBUG MARKER: == sanity test 151: test cache on oss and controls ========================================================================================= 08:13:12 (1778933592) [10736.104078] Lustre: DEBUG MARKER: SKIP: sanity test_151 not cache-capable obdfilter [10736.977775] Lustre: DEBUG MARKER: == sanity test 152: test read/write with enomem ====================================================================================== 08:13:14 (1778933594) [10739.581592] Lustre: DEBUG MARKER: == sanity test 153: test if fdatasync does not crash ================================================================================= 08:13:17 (1778933597) [10742.768754] Lustre: DEBUG MARKER: == sanity test 154A: lfs path2fid and fid2path basic checks ========================================================== 08:13:20 (1778933600) [10745.793762] Lustre: DEBUG MARKER: == sanity test 154B: verify the ll_decode_linkea tool ==== 08:13:23 (1778933603) [10748.854850] Lustre: DEBUG MARKER: == sanity test 154C: lfs fid2path on OST FID ============= 08:13:26 (1778933606) [10770.047781] Lustre: DEBUG MARKER: == sanity test 154a: Open-by-FID ========================= 08:13:48 (1778933628) [10770.767392] LustreError: 107852:0:(fld_handler.c:268:fld_server_lookup()) srv-lustre-MDT0000: Cannot find sequence 0xf00000400: rc = -2 [10774.315457] Lustre: DEBUG MARKER: == sanity test 154b: Open-by-FID for remote directory ==== 08:13:52 (1778933632) [10775.079942] Lustre: DEBUG MARKER: SKIP: sanity test_154b needs >= 2 MDTs [10775.945384] Lustre: DEBUG MARKER: == sanity test 154c: lfs path2fid and fid2path multiple arguments ========================================================== 08:13:53 (1778933633) [10779.208810] Lustre: DEBUG MARKER: == sanity test 154d: Verify open file fid ================ 08:13:57 (1778933637) [10782.679296] Lustre: DEBUG MARKER: == sanity test 154e: .lustre is not returned by readdir == 08:14:00 (1778933640) [10785.819351] Lustre: DEBUG MARKER: == sanity test 154ea: .lustre is not returned by readdir (2) ========================================================== 08:14:03 (1778933643) [10810.294105] Lustre: DEBUG MARKER: == sanity test 154f: get parent fids by reading link ea == 08:14:28 (1778933668) [10814.040570] Lustre: DEBUG MARKER: == sanity test 154g: various llapi FID tests ============= 08:14:32 (1778933672) [11306.697239] Lustre: DEBUG MARKER: == sanity test 154h: Verify interactive path2fid ========= 08:22:44 (1778934164) [11309.804232] Lustre: DEBUG MARKER: == sanity test 154i: fid2path for path longer than PATH_MAX ========================================================== 08:22:47 (1778934167) [11329.616555] Lustre: DEBUG MARKER: == sanity test 154j: fid2path for long path crossing MDT boundary ========================================================== 08:23:07 (1778934187) [11330.420655] Lustre: DEBUG MARKER: SKIP: sanity test_154j needs >= 2 MDTs [11331.353920] Lustre: DEBUG MARKER: == sanity test 155a: Verify small file correctness: read cache:on write_cache:on ========================================================== 08:23:09 (1778934189) [11336.980060] Lustre: DEBUG MARKER: == sanity test 155b: Verify small file correctness: read cache:on write_cache:off ========================================================== 08:23:14 (1778934194) [11343.334980] Lustre: DEBUG MARKER: == sanity test 155c: Verify small file correctness: read cache:off write_cache:on ========================================================== 08:23:21 (1778934201) [11349.305804] Lustre: DEBUG MARKER: == sanity test 155d: Verify small file correctness: read cache:off write_cache:off ========================================================== 08:23:27 (1778934207) [11355.422765] Lustre: DEBUG MARKER: == sanity test 155e: Verify big file correctness: read cache:on write_cache:on ========================================================== 08:23:33 (1778934213) [11388.505832] Lustre: DEBUG MARKER: == sanity test 155f: Verify big file correctness: read cache:on write_cache:off ========================================================== 08:24:06 (1778934246) [11421.862983] Lustre: DEBUG MARKER: == sanity test 155g: Verify big file correctness: read cache:off write_cache:on ========================================================== 08:24:39 (1778934279) [11449.254987] Lustre: DEBUG MARKER: == sanity test 155h: Verify big file correctness: read cache:off write_cache:off ========================================================== 08:25:07 (1778934307) [11487.140725] Lustre: DEBUG MARKER: == sanity test 156: Verification of tunables ============= 08:25:45 (1778934345) [11488.072911] Lustre: DEBUG MARKER: SKIP: sanity test_156 LU-1956/LU-2261: stats not implemented on OSD ZFS [11488.998617] Lustre: DEBUG MARKER: == sanity test 157: llapi pool pinning API tests ========= 08:25:46 (1778934346) [11492.649722] Lustre: DEBUG MARKER: == sanity test 157a: lustre.pin inheritance on create ==== 08:25:50 (1778934350) [11496.333410] Lustre: DEBUG MARKER: == sanity test 160a: changelog sanity ==================== 08:25:54 (1778934354) [11497.732176] Lustre: lustre-MDD0000: changelog on [11505.177461] Lustre: Failing over lustre-MDT0000 [11505.462760] Lustre: server umount lustre-MDT0000 complete [11508.939581] LustreError: MGC192.168.204.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [11509.068962] 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 [11509.075030] Lustre: Skipped 1 previous similar message [11509.121067] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [11509.145660] Lustre: lustre-MDD0000: changelog on [11509.153447] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [11510.675607] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [11510.882227] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [11511.095685] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [11511.111987] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000403:8542 to 0x240000403:8577) [11511.112345] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000403:8546 to 0x280000403:8577) [11512.965307] Lustre: lustre-MDD0000: changelog off [11514.345224] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [11517.385409] Lustre: DEBUG MARKER: == sanity test 160b: Verify that very long rename doesn't crash in changelog ========================================================== 08:26:15 (1778934375) [11518.746035] Lustre: lustre-MDD0000: changelog on [11522.877687] Lustre: lustre-MDD0000: changelog off [11524.088356] Lustre: DEBUG MARKER: == sanity test 160c: verify that changelog log catch the truncate event ========================================================== 08:26:22 (1778934382) [11525.468525] Lustre: lustre-MDD0000: changelog on [11529.854953] Lustre: lustre-MDD0000: changelog off [11531.121214] Lustre: DEBUG MARKER: == sanity test 160d: verify that changelog log catch the migrate event ========================================================== 08:26:29 (1778934389) [11532.024415] Lustre: DEBUG MARKER: SKIP: sanity test_160d needs >= 2 MDTs [11532.915419] Lustre: DEBUG MARKER: == sanity test 160e: changelog negative testing (should return errors) ========================================================== 08:26:30 (1778934390) [11534.387606] Lustre: lustre-MDD0000: changelog on [11538.097658] Lustre: lustre-MDD0000: changelog off [11539.406682] Lustre: DEBUG MARKER: == sanity test 160f: changelog garbage collect (timestamped users) ========================================================== 08:26:37 (1778934397) [11543.106952] Lustre: DEBUG MARKER: 1778934401: creating first dirs [11554.338334] Lustre: *** cfs_fail_loc=1313, val=3*** [11554.341163] Lustre: 176593:0:(mdd_dir.c:971:mdd_changelog_emrg_cleanup()) lustre-MDD0000: changelog has only 3 free catalog entries [11554.347950] Lustre: 176593:0:(mdd_dir.c:1054:mdd_changelog_store()) lustre-MDD0000: starting changelog garbage collection [11554.356162] Lustre: 180031:0:(mdd_trans.c:163:mdd_chlg_garbage_collect()) lustre-MDD0000: force deregister of changelog user cl6 idle for 12s with 4 unprocessed records [11565.982197] Lustre: lustre-MDD0000: changelog off [11566.903434] Lustre: DEBUG MARKER: == sanity test 160g: changelog garbage collect on idle records ========================================================== 08:27:05 (1778934425) [11567.810555] Lustre: lustre-MDD0000: changelog on [11567.812095] Lustre: Skipped 1 previous similar message [11574.093660] Lustre: 176301:0:(mdd_dir.c:1054:mdd_changelog_store()) lustre-MDD0000: starting changelog garbage collection [11574.101613] Lustre: 181630:0:(mdd_trans.c:163:mdd_chlg_garbage_collect()) lustre-MDD0000: force deregister of changelog user cl8 idle for 5s with 4 unprocessed records [11580.892788] Lustre: lustre-MDD0000: changelog off [11581.768208] Lustre: DEBUG MARKER: == sanity test 160h: changelog gc thread stop upon umount, orphan records delete ========================================================== 08:27:20 (1778934440) [11600.668124] Lustre: *** cfs_fail_loc=1316, val=0*** [11600.671107] Lustre: 176593:0:(mdd_dir.c:1054:mdd_changelog_store()) lustre-MDD0000: simulate starting changelog garbage collection [11600.679329] Lustre: 183224:0:(mdd_trans.c:163:mdd_chlg_garbage_collect()) lustre-MDD0000: force deregister of changelog user cl10 idle for 16s with 4 unprocessed records [11601.341758] Lustre: Failing over lustre-MDT0000 [11601.378128] 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 [11601.383492] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [11602.831361] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.1@tcp (stopping) [11602.833547] Lustre: Skipped 1 previous similar message [11603.467555] Lustre: server umount lustre-MDT0000 complete [11606.633310] LustreError: MGC192.168.204.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [11606.892542] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [11606.927291] Lustre: lustre-MDD0000: changelog on [11606.928833] Lustre: Skipped 1 previous similar message [11606.931126] Lustre: 184126:0:(mdd_device.c:626:mdd_changelog_llog_init()) lustre-MDD0000 : orphan changelog records found, starting from index 34 to index 35, being cleared now [11606.943438] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [11607.945833] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [11608.379205] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [11608.395449] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000403:8579 to 0x240000403:8609) [11608.395747] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000403:8546 to 0x280000403:8609) [11608.575658] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [11616.231942] Lustre: lustre-MDD0000: changelog off [11617.532525] Lustre: DEBUG MARKER: == sanity test 160i: changelog user register/unregister race ========================================================== 08:27:55 (1778934475) [11620.882742] LustreError: 185576:0:(mdd_device.c:2065:mdd_changelog_user_purge()) cfs_race id 1315 sleeping [11621.352812] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [11621.357022] Lustre: Skipped 1 previous similar message [11623.424811] LustreError: 185709:0:(mdd_device.c:1780:mdd_changelog_user_register()) cfs_fail_race id 1315 waking [11623.430190] LustreError: 185576:0:(mdd_device.c:2065:mdd_changelog_user_purge()) cfs_fail_race id 1315 awake: rc=2457 [11630.184652] Lustre: DEBUG MARKER: == sanity test 160j: client can be umounted while its chanangelog is being used ========================================================== 08:28:08 (1778934488) [11637.337292] Lustre: DEBUG MARKER: == sanity test 160k: Verify that changelog records are not lost ========================================================== 08:28:15 (1778934495) [11639.681163] LustreError: 184336:0:(mdd_dir.c:1026:mdd_changelog_store()) cfs_fail_timeout id 15d sleeping for 3000ms [11642.704125] LustreError: 184336:0:(mdd_dir.c:1026:mdd_changelog_store()) cfs_fail_timeout id 15d awake [11648.925621] Lustre: lustre-MDD0000: changelog off [11648.926958] Lustre: Skipped 3 previous similar messages [11650.133655] Lustre: DEBUG MARKER: == sanity test 160l: Verify that MTIME changelog records contain the parent FID ========================================================== 08:28:28 (1778934508) [11651.533184] Lustre: lustre-MDD0000: changelog on [11651.535478] Lustre: Skipped 4 previous similar messages [11659.217305] Lustre: DEBUG MARKER: == sanity test 160m: Changelog clear race ================ 08:28:37 (1778934517) [11663.872104] LustreError: 184136:0:(mdd_device.c:398:llog_changelog_cancel_cb()) cfs_race id 15f sleeping [11665.877698] LustreError: 184286:0:(mdd_device.c:398:llog_changelog_cancel_cb()) cfs_fail_race id 15f waking [11665.883519] LustreError: 184136:0:(mdd_device.c:398:llog_changelog_cancel_cb()) cfs_fail_race id 15f awake: rc=2994 [11670.779517] Lustre: DEBUG MARKER: == sanity test 160n: Changelog destroy race ============== 08:28:49 (1778934529) [12543.743965] LustreError: 184286:0:(mdd_device.c:412:llog_changelog_cancel_cb()) cfs_race id 16c sleeping [12545.749279] LustreError: 184136:0:(llog_osd.c:1130:llog_osd_next_block()) cfs_fail_race id 16c waking [12545.754647] LustreError: 184286:0:(mdd_device.c:412:llog_changelog_cancel_cb()) cfs_fail_race id 16c awake: rc=2996 [12552.705509] Lustre: lustre-MDD0000: changelog off [12552.708138] Lustre: Skipped 2 previous similar messages [12554.030336] Lustre: DEBUG MARKER: == sanity test 160o: changelog user name and mask ======== 08:43:31 (1778935411) [12555.474760] Lustre: lustre-MDD0000: changelog on [12555.477414] Lustre: Skipped 2 previous similar messages [12555.899829] LustreError: 191361:0:(mdd_device.c:1734:mdd_changelog_name_check()) lustre-MDD0000: wrong char '#' in name 'Tt3_-#': rc = -22 [12556.325506] Lustre: 191409:0:(mdd_device.c:1751:mdd_changelog_name_check()) lustre-MDD0000: changelog name test_160o exists already: rc = -17 [12556.747235] LustreError: 191457:0:(mdd_device.c:1743:mdd_changelog_name_check()) lustre-MDD0000: name 'test_160toolongname' is over 16 symbols limit: rc = -36 [12566.176236] Lustre: lustre-MDD0000: changelog off [12568.335668] Lustre: DEBUG MARKER: == sanity test 160p: Changelog orphan cleanup with no users ========================================================== 08:43:46 (1778935426) [12569.241376] Lustre: DEBUG MARKER: SKIP: sanity test_160p ldiskfs only test [12570.150981] Lustre: DEBUG MARKER: == sanity test 160q: changelog effective mask is DEFMASK if not set ========================================================== 08:43:48 (1778935428) [12571.359492] Lustre: lustre-MDD0000: changelog on [12575.401939] Lustre: DEBUG MARKER: == sanity test 160s: changelog garbage collect on idle records * time ========================================================== 08:43:53 (1778935433) [12585.059383] Lustre: 184336:0:(mdd_dir.c:1054:mdd_changelog_store()) lustre-MDD0000: starting changelog garbage collection [12585.067363] Lustre: 193605:0:(mdd_trans.c:163:mdd_chlg_garbage_collect()) lustre-MDD0000: force deregister of changelog user cl24 idle for 864007s with 500000004 unprocessed records [12585.077331] Lustre: lustre-MDD0000: changelog off [12585.080062] Lustre: Skipped 1 previous similar message [12592.594176] Lustre: DEBUG MARKER: == sanity test 160t: changelog garbage collect on lack of space ========================================================== 08:44:10 (1778935450) [12594.021708] Lustre: lustre-MDD0000: changelog on [12594.024302] Lustre: Skipped 1 previous similar message [12618.583945] Lustre: *** cfs_fail_loc=18c, val=1211660*** [12618.586991] Lustre: 184135:0:(mdd_dir.c:1054:mdd_changelog_store()) lustre-MDD0000: starting changelog garbage collection [12618.594571] Lustre: 195189:0:(mdd_dir.c:942:mdd_changelog_is_space_safe()) lustre-MDD0000: changelog size 1MB with 1MB space limit [12618.602408] Lustre: 195189:0:(mdd_trans.c:163:mdd_chlg_garbage_collect()) lustre-MDD0000: force deregister of changelog user cl25-user1 idle for 25s with 7506 unprocessed records [12625.839317] Lustre: lustre-MDD0000: changelog off [12637.612813] Lustre: DEBUG MARKER: == sanity test 160u: changelog rename record type name and sname strings are correct ========================================================== 08:44:55 (1778935495) [12641.095178] Lustre: lustre-MDD0000: changelog on [12647.360262] Lustre: DEBUG MARKER: == sanity test 160v: setattr preserves mtime update despite inter-client clock skew ========================================================== 08:45:05 (1778935505) [12648.181952] Lustre: DEBUG MARKER: SKIP: sanity test_160v need >= 2 clients [12649.175709] Lustre: DEBUG MARKER: == sanity test 160w: lfs changelog --user --mask ========= 08:45:07 (1778935507) [12660.217582] Lustre: DEBUG MARKER: == sanity test 161a: link ea sanity ====================== 08:45:18 (1778935518) [12677.158199] Lustre: DEBUG MARKER: == sanity test 161b: link ea sanity under remote directory ========================================================== 08:45:35 (1778935535) [12678.010432] Lustre: DEBUG MARKER: SKIP: sanity test_161b skipping remote directory test [12678.992579] Lustre: DEBUG MARKER: == sanity test 161c: check CL_RENME[UNLINK] changelog record flags ========================================================== 08:45:36 (1778935536) [12687.432349] Lustre: DEBUG MARKER: == sanity test 161d: create with concurrent .lustre/fid access ========================================================== 08:45:45 (1778935545) [12694.810841] Lustre: lustre-MDD0000: changelog off [12694.813468] Lustre: Skipped 3 previous similar messages [12696.150379] Lustre: DEBUG MARKER: == sanity test 162a: path lookup sanity ================== 08:45:54 (1778935554) [12700.342462] Lustre: DEBUG MARKER: == sanity test 162b: striped directory path lookup sanity ========================================================== 08:45:58 (1778935558) [12701.198568] Lustre: DEBUG MARKER: SKIP: sanity test_162b needs >= 2 MDTs [12702.182236] Lustre: DEBUG MARKER: == sanity test 162c: fid2path works with paths 100 or more directories deep ========================================================== 08:46:00 (1778935560) [12729.393543] Lustre: DEBUG MARKER: == sanity test 165a: ofd access log discovery ============ 08:46:27 (1778935587) [12736.201149] Lustre: Failing over lustre-OST0000 [12736.355782] Lustre: server umount lustre-OST0000 complete [12737.507289] 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 [12737.513372] Lustre: Skipped 1 previous similar message [12742.627252] LustreError: 161834:0:(ldlm_lib.c:1180: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. [12742.637819] LustreError: 161834:0:(ldlm_lib.c:1180:target_handle_connect()) Skipped 3 previous similar messages [12744.914330] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12744.924613] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [12746.122464] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [12746.645770] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [12746.646433] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12746.653984] Lustre: Skipped 1 previous similar message [12747.590689] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [12749.481787] Lustre: DEBUG MARKER: == sanity test 165b: ofd access log entries are produced and consumed ========================================================== 08:46:47 (1778935607) [12775.695052] Lustre: Failing over lustre-OST0000 [12775.704481] LustreError: 201918:0:(ldlm_resource.c:1180:ldlm_resource_complain()) filter-lustre-OST0000_UUID: namespace resource [0x240000403:0x48c6:0x0].0x0 (ffff8f54c2ee2d00) refcount nonzero (2) after lock cleanup; forcing cleanup. [12775.907734] 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 [12775.917043] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [12776.855275] Lustre: lustre-OST0000: Not available for connect from 192.168.204.1@tcp (stopping) [12777.796558] Lustre: server umount lustre-OST0000 complete [12781.027587] LustreError: 167671:0:(ldlm_lib.c:1180: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. [12781.437755] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12781.447914] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [12781.962785] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [12783.511745] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12783.511915] Lustre: lustre-OST0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [12784.145933] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [12786.002638] Lustre: DEBUG MARKER: == sanity test 165c: full ofd access logs do not block IOs ========================================================== 08:47:23 (1778935643) [12801.755257] Lustre: Failing over lustre-OST0000 [12802.020100] 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 [12802.030803] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [12803.852778] Lustre: server umount lustre-OST0000 complete [12807.141116] LustreError: 167672:0:(ldlm_lib.c:1180: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. [12807.411858] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12807.421576] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [12807.562170] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [12808.658182] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [12808.662365] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12810.010975] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [12811.839217] Lustre: DEBUG MARKER: == sanity test 165d: ofd_access_log mask works =========== 08:47:49 (1778935669) [12839.506964] Lustre: Failing over lustre-OST0000 [12841.603199] Lustre: server umount lustre-OST0000 complete [12843.416300] LustreError: 167675:0:(ldlm_lib.c:1180:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.1@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [12843.491541] 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 [12845.172764] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12845.183345] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [12846.628429] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [12847.228048] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12847.228180] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [12847.672973] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [12849.516191] Lustre: DEBUG MARKER: == sanity test 165e: ofd_access_log MDT index filter works ========================================================== 08:48:27 (1778935707) [12850.365105] Lustre: DEBUG MARKER: SKIP: sanity test_165e needs >= 2 MDTs [12851.310289] Lustre: DEBUG MARKER: == sanity test 165f: ofd_access_log_reader --exit-on-close works ========================================================== 08:48:29 (1778935709) [12857.665860] Lustre: Failing over lustre-OST0000 [12857.675915] LustreError: 206944:0:(ldlm_resource.c:1180:ldlm_resource_complain()) filter-lustre-OST0000_UUID: namespace resource [0x240000403:0x48c6:0x0].0x0 (ffff8f54fbb00100) refcount nonzero (2) after lock cleanup; forcing cleanup. [12857.825430] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [12857.830711] 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 [12857.839975] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [12857.844101] Lustre: Skipped 1 previous similar message [12859.789613] Lustre: server umount lustre-OST0000 complete [12860.900111] LustreError: 161834:0:(ldlm_lib.c:1180: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. [12860.910903] LustreError: 161834:0:(ldlm_lib.c:1180:target_handle_connect()) Skipped 1 previous similar message [12867.799415] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12867.809471] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [12869.002832] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [12869.333565] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12869.333794] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [12870.405988] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [12872.251216] Lustre: DEBUG MARKER: == sanity test 165g: ofd_access_log_reader --keepalive works ========================================================== 08:48:50 (1778935730) [12914.009190] Lustre: Failing over lustre-OST0000 [12914.018279] LustreError: 208462:0:(ldlm_resource.c:1180:ldlm_resource_complain()) filter-lustre-OST0000_UUID: namespace resource [0x240000403:0x48c6:0x0].0x0 (ffff8f54c899d000) refcount nonzero (2) after lock cleanup; forcing cleanup. [12914.147066] 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 [12914.156469] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [12914.160677] Lustre: Skipped 1 previous similar message [12916.099163] Lustre: server umount lustre-OST0000 complete [12919.268850] LustreError: 161844:0:(ldlm_lib.c:1180: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. [12919.279697] LustreError: 161844:0:(ldlm_lib.c:1180:target_handle_connect()) Skipped 2 previous similar messages [12924.670265] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12924.680714] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [12925.322147] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [12925.905914] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [12925.908831] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12927.308701] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing set_default_debug all all [12929.145352] Lustre: DEBUG MARKER: == sanity test 169: parallel read and truncate should not deadlock ========================================================== 08:49:47 (1778935787) [12930.000152] Lustre: DEBUG MARKER: creating a 10 Mb file [12941.223391] Lustre: DEBUG MARKER: starting reads [12941.914294] Lustre: DEBUG MARKER: truncating the file [12942.944229] Lustre: DEBUG MARKER: killing dd [12943.806516] Lustre: DEBUG MARKER: removing the temporary file [12947.232048] Lustre: DEBUG MARKER: == sanity test 170a: test lctl df to handle corrupted log ========================================================== 08:50:05 (1778935805) [12951.287156] Lustre: DEBUG MARKER: == sanity test 170b: check filename encoding ============= 08:50:09 (1778935809) [12965.162666] Lustre: DEBUG MARKER: == sanity test 171: test libcfs_debug_dumplog_thread stuck in do_exit() ================================================================ 08:50:23 (1778935823) [12971.856935] Lustre: DEBUG MARKER: == sanity test 172: manual device removal with lctl cleanup/detach ================================================================ 08:50:29 (1778935829) [12976.323415] Lustre: DEBUG MARKER: == sanity test 180a: test obdecho on osc ================= 08:50:34 (1778935834) [12977.166183] Lustre: DEBUG MARKER: SKIP: sanity test_180a obdecho on osc is no longer supported [12978.116848] Lustre: DEBUG MARKER: == sanity test 180b: test obdecho directly on obdfilter == 08:50:36 (1778935836) [12979.583177] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_module obdecho/obdecho [12988.324687] Lustre: DEBUG MARKER: == sanity test 180c: test huge bulk I/O size on obdfilter, don't LASSERT ========================================================== 08:50:46 (1778935846) [12989.853287] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing load_module obdecho/obdecho [12989.926954] Lustre: Echo OBD driver; http://www.lustre.org/ [12999.359983] Lustre: DEBUG MARKER: == sanity test 181: Test open-unlinked dir ================================================================================== 08:50:57 (1778935857) [13034.899782] Lustre: DEBUG MARKER: == sanity test 182a: Test parallel modify metadata operations from mdc ========================================================== 08:51:33 (1778935893) [13039.169914] ODEBUG: object 0000000048887cdb is on stack 000000001a6d916f, but NOT annotated. [13039.171630] WARNING: CPU: 2 PID: 184135 at lib/debugobjects.c:368 __debug_object_init.cold.5+0x35/0x15f [13039.174248] Modules linked in: lustre(O) osp(O) ofd(O) lod(O) mdt(O) mdd(O) mgs(O) osd_zfs(O) lquota(O) lfsck(O) mgc(O) mdc(O) lov(O) osc(O) lmv(O) fid(O) fld(O) ptlrpc_gss(O) ptlrpc(O) obdclass(O) ksocklnd(O) lnet(O) libcfs(O) ec(O) zfs(O) spl(O) rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver intel_rapl_msr intel_rapl_common sb_edac rapl pcspkr i2c_piix4 squashfs ata_generic crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw ata_piix libata dm_mirror dm_region_hash dm_log dm_mod sha512_ssse3 sha512_generic [last unloaded: obdecho] [13039.186092] CPU: 2 PID: 184135 Comm: mdt00_000 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [13039.188846] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [13039.191069] RIP: 0010:__debug_object_init.cold.5+0x35/0x15f [13039.192382] Code: 5e 8f 48 83 05 23 61 0c 03 01 89 05 59 69 0c 03 65 48 8b 04 25 00 dd 01 00 48 8b 50 18 e8 93 68 99 ff 48 83 05 1b 61 0c 03 01 <0f> 0b 48 83 05 19 61 0c 03 01 48 83 05 19 61 0c 03 01 e9 3f ee ff [13039.196912] RSP: 0018:ffffae1802c67480 EFLAGS: 00010002 [13039.198226] RAX: 0000000000000050 RBX: ffffae1802c67588 RCX: 0000000000000000 [13039.200461] RDX: 0000000000000000 RSI: ffff8f550211e5a8 RDI: ffff8f550211e5a8 [13039.202407] RBP: ffffffff8fd06ae0 R08: 0000000000000000 R09: c0000000ffff7fff [13039.204641] R10: 0000000000000001 R11: ffffae1802c67278 R12: ffffffff914ff468 [13039.206399] R13: 0000000000011c80 R14: ffffffff914ff460 R15: ffff8f54249d3528 [13039.208422] FS: 0000000000000000(0000) GS:ffff8f5502100000(0000) knlGS:0000000000000000 [13039.210411] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [13039.212027] CR2: 00007fb532e31000 CR3: 0000000097e16004 CR4: 0000000000170ee0 [13039.213514] Call Trace: [13039.214250] ? show_regs.cold.9+0x22/0x2f [13039.215188] ? __warn+0xc8/0x150 [13039.216044] ? __debug_object_init.cold.5+0x35/0x15f [13039.217400] ? report_bug+0x113/0x140 [13039.218482] ? do_error_trap+0xb6/0x130 [13039.219554] ? do_invalid_op+0x46/0x60 [13039.220814] ? __debug_object_init.cold.5+0x35/0x15f [13039.222521] ? invalid_op+0x14/0x20 [13039.223407] ? __debug_object_init.cold.5+0x35/0x15f [13039.224642] ? lod_set_pool+0x260/0x260 [lod] [13039.225908] debug_object_init+0x22/0x30 [13039.226809] init_timer_key+0x28/0x120 [13039.227901] lod_ost_alloc_qos+0x790/0x1c60 [lod] [13039.228936] ? slab_post_alloc_hook+0x66/0x380 [13039.230269] ? lod_qos_prep_create+0x390/0x1bc0 [lod] [13039.231590] ? __kmalloc+0x1b4/0x4a0 [13039.232788] lod_qos_prep_create+0x134e/0x1bc0 [lod] [13039.233795] ? osd_idc_add.isra.15+0x30/0x520 [osd_zfs] [13039.234518] ODEBUG: object 00000000b6e39213 is on stack 000000004af8697c, but NOT annotated. [13039.235185] lod_prepare_create+0x204/0x460 [lod] [13039.237290] WARNING: CPU: 0 PID: 184136 at lib/debugobjects.c:368 __debug_object_init.cold.5+0x35/0x15f [13039.238850] lod_declare_striped_create+0x270/0xf80 [lod] [13039.241451] Modules linked in: lustre(O) osp(O) ofd(O) lod(O) mdt(O) mdd(O) mgs(O) osd_zfs(O) lquota(O) lfsck(O) [13039.243343] ? lod_sub_declare_create+0x111/0x320 [lod] [13039.243362] mgc(O) mdc(O) lov(O) osc(O) lmv(O) fid(O) fld(O) ptlrpc_gss(O) ptlrpc(O) obdclass(O) ksocklnd(O) lnet(O) libcfs(O) [13039.247310] lod_declare_create+0x22f/0xb60 [lod] [13039.247329] ec(O) zfs(O) spl(O) rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver intel_rapl_msr intel_rapl_common sb_edac rapl pcspkr i2c_piix4 squashfs ata_generic crct10dif_pclmul [13039.252122] ? osd_xattr_get+0x2d8/0x8d0 [osd_zfs] [13039.256160] crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw ata_piix libata dm_mirror dm_region_hash dm_log dm_mod sha512_ssse3 sha512_generic [last unloaded: obdecho] [13039.257371] mdd_declare_create_object_internal+0x107/0x4a0 [mdd] [13039.262170] CPU: 0 PID: 184136 Comm: mdt00_001 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [13039.263913] mdd_declare_create_object.isra.25+0x55/0xd30 [mdd] [13039.267115] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [13039.268915] mdd_declare_create+0x71/0x6d0 [mdd] [13039.271585] RIP: 0010:__debug_object_init.cold.5+0x35/0x15f [13039.273310] ? linkea_add_buf+0xa8/0x4c0 [obdclass] [13039.275036] Code: 5e 8f 48 83 05 23 61 0c 03 01 89 05 59 69 0c 03 65 48 8b 04 25 00 dd 01 00 48 8b 50 18 e8 93 68 99 ff 48 83 05 1b 61 0c 03 01 <0f> 0b 48 83 05 19 61 0c 03 01 48 83 05 19 61 0c 03 01 e9 3f ee ff [13039.276635] mdd_create+0x6e3/0x2270 [mdd] [13039.281767] ODEBUG: object 00000000ded2ede4 is on stack 000000003ee09435, but NOT annotated. [13039.281787] WARNING: CPU: 3 PID: 189408 at lib/debugobjects.c:368 __debug_object_init.cold.5+0x35/0x15f [13039.281796] Modules linked in: lustre(O) osp(O) ofd(O) lod(O) mdt(O) mdd(O) mgs(O) osd_zfs(O) lquota(O) lfsck(O) mgc(O) mdc(O) lov(O) osc(O) lmv(O) fid(O) fld(O) ptlrpc_gss(O) ptlrpc(O) obdclass(O) ksocklnd(O) lnet(O) libcfs(O) ec(O) zfs(O) spl(O) rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver intel_rapl_msr intel_rapl_common sb_edac rapl pcspkr i2c_piix4 squashfs ata_generic crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw ata_piix libata dm_mirror dm_region_hash dm_log dm_mod sha512_ssse3 sha512_generic [last unloaded: obdecho] [13039.281906] CPU: 3 PID: 189408 Comm: mdt00_005 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [13039.281910] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [13039.281911] RIP: 0010:__debug_object_init.cold.5+0x35/0x15f [13039.281917] Code: 5e 8f 48 83 05 23 61 0c 03 01 89 05 59 69 0c 03 65 48 8b 04 25 00 dd 01 00 48 8b 50 18 e8 93 68 99 ff 48 83 05 1b 61 0c 03 01 <0f> 0b 48 83 05 19 61 0c 03 01 48 83 05 19 61 0c 03 01 e9 3f ee ff [13039.281922] RSP: 0018:ffffae1803043480 EFLAGS: 00010006 [13039.281927] RAX: 0000000000000050 RBX: ffffae1803043588 RCX: 0000000000000000 [13039.281929] RDX: 0000000000000000 RSI: ffff8f550219e5a8 RDI: ffff8f550219e5a8 [13039.281930] RBP: ffffffff8fd06ae0 R08: ffffffff8f905780 R09: 0000000000000034 [13039.281934] R10: 0000000000000bfa R11: 0000000000000bfa R12: ffffffff91530388 [13039.281936] R13: 0000000000042ba0 R14: ffffffff91530380 R15: ffff8f541b5bce38 [13039.281938] FS: 0000000000000000(0000) GS:ffff8f5502180000(0000) knlGS:0000000000000000 [13039.281942] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [13039.281944] CR2: 00007f534307e030 CR3: 0000000097e16003 CR4: 0000000000170ee0 [13039.281951] Call Trace: [13039.281955] ? show_regs.cold.9+0x22/0x2f [13039.281960] ? __warn+0xc8/0x150 [13039.281967] ? __debug_object_init.cold.5+0x35/0x15f [13039.281971] ? report_bug+0x113/0x140 [13039.281977] ? do_error_trap+0xb6/0x130 [13039.281981] ? do_invalid_op+0x46/0x60 [13039.281984] ? __debug_object_init.cold.5+0x35/0x15f [13039.281988] ? invalid_op+0x14/0x20 [13039.281993] ? __debug_object_init.cold.5+0x35/0x15f [13039.281997] ? lod_set_pool+0x260/0x260 [lod] [13039.282042] debug_object_init+0x22/0x30 [13039.282046] init_timer_key+0x28/0x120 [13039.282051] lod_ost_alloc_qos+0x790/0x1c60 [lod] [13039.282087] ? slab_post_alloc_hook+0x66/0x380 [13039.282093] ? lod_qos_prep_create+0x390/0x1bc0 [lod] [13039.282127] ? __kmalloc+0x1b4/0x4a0 [13039.282132] lod_qos_prep_create+0x134e/0x1bc0 [lod] [13039.282167] ? osd_idc_add.isra.15+0x30/0x520 [osd_zfs] [13039.282193] lod_prepare_create+0x204/0x460 [lod] [13039.282229] lod_declare_striped_create+0x270/0xf80 [lod] [13039.282262] ? lod_sub_declare_create+0x111/0x320 [lod] [13039.282295] lod_declare_create+0x22f/0xb60 [lod] [13039.282328] ? osd_xattr_get+0x2d8/0x8d0 [osd_zfs] [13039.282351] mdd_declare_create_object_internal+0x107/0x4a0 [mdd] [13039.282382] mdd_declare_create_object.isra.25+0x55/0xd30 [mdd] [13039.282407] mdd_declare_create+0x71/0x6d0 [mdd] [13039.282473] RSP: 0018:ffffae1802c6f480 EFLAGS: 00010002 [13039.282431] ? linkea_add_buf+0xa8/0x4c0 [obdclass] [13039.282523] mdd_create+0x6e3/0x2270 [mdd] [13039.282550] ? mdt_version_save+0xa8/0x210 [mdt] [13039.282622] mdt_reint_open+0x35dd/0x3c80 [mdt] [13039.282675] ? old_init_ucred_common+0x19e/0x820 [mdt] [13039.282723] mdt_reint_rec+0x139/0x2b0 [mdt] [13039.282772] mdt_reint_internal+0x693/0xdc0 [mdt] [13039.282830] mdt_intent_open+0x180/0x5b0 [mdt] [13039.282878] mdt_intent_opc.constprop.43+0x153/0xfb0 [mdt] [13039.282924] ? mdt_intent_fixup_resent+0x2e0/0x2e0 [mdt] [13039.282972] mdt_intent_policy+0x14b/0x670 [mdt] [13039.283020] ldlm_lock_enqueue+0x43c/0xcd0 [ptlrpc] [13039.283209] ? _raw_read_unlock+0x12/0x30 [13039.283213] ? cfs_hash_rw_unlock+0x11/0x30 [obdclass] [13039.283296] ? mdt_version_save+0xa8/0x210 [mdt] [13039.283286] ldlm_handle_enqueue+0xcaf/0x2280 [ptlrpc] [13039.283662] tgt_enqueue+0xd0/0x300 [ptlrpc] [13039.283815] tgt_handle_request0+0x137/0xaf0 [ptlrpc] [13039.283957] tgt_request_handle+0x575/0x1f70 [ptlrpc] [13039.284099] ? obd_export_timed_fini+0xc4/0xe0 [obdclass] [13039.284170] ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [13039.284296] ? __wake_up+0x17/0x20 [13039.284301] ? ptlrpc_server_handle_req_in+0x96c/0xe10 [ptlrpc] [13039.284426] ptlrpc_main+0xce8/0x1400 [ptlrpc] [13039.284550] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [13039.284674] kthread+0x1d1/0x200 [13039.284677] ? set_kthread_struct+0x70/0x70 [13039.284680] ret_from_fork+0x1f/0x30 [13039.284684] ---[ end trace 8066fd2da60cfde7 ]--- [13039.284716] [13039.287243] mdt_reint_open+0x35dd/0x3c80 [mdt] [13039.302473] RAX: 0000000000000050 RBX: ffffae1802c6f588 RCX: 0000000000000000 [13039.305934] ? old_init_ucred_common+0x19e/0x820 [mdt] [13039.308899] RDX: 0000000000000000 RSI: ffff8f550201e5a8 RDI: ffff8f550201e5a8 [13039.310712] mdt_reint_rec+0x139/0x2b0 [mdt] [13039.316630] RBP: ffffffff8fd06ae0 R08: 30207463656a626f R09: 203a47554245444f [13039.318427] mdt_reint_internal+0x693/0xdc0 [mdt] [13039.320805] R10: 30207463656a626f R11: 203a47554245444f R12: ffffffff91506688 [13039.322657] mdt_intent_open+0x180/0x5b0 [mdt] [13039.325051] R13: 0000000000018ea0 R14: ffffffff91506680 R15: ffff8f53c24b48c0 [13039.326918] mdt_intent_opc.constprop.43+0x153/0xfb0 [mdt] [13039.328990] FS: 0000000000000000(0000) GS:ffff8f5502000000(0000) knlGS:0000000000000000 [13039.331569] ? mdt_intent_fixup_resent+0x2e0/0x2e0 [mdt] [13039.333420] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [13039.335744] mdt_intent_policy+0x14b/0x670 [mdt] [13039.336683] CR2: 000056029ae25bb8 CR3: 0000000097e16001 CR4: 0000000000170ef0 [13039.337885] ldlm_lock_enqueue+0x43c/0xcd0 [ptlrpc] [13039.338674] Call Trace: [13039.340078] ? _raw_read_unlock+0x12/0x30 [13039.341070] ? show_regs.cold.9+0x22/0x2f [13039.342250] ? cfs_hash_rw_unlock+0x11/0x30 [obdclass] [13039.343333] ? __warn+0xc8/0x150 [13039.344386] ldlm_handle_enqueue+0xcaf/0x2280 [ptlrpc] [13039.345378] ? __debug_object_init.cold.5+0x35/0x15f [13039.346941] tgt_enqueue+0xd0/0x300 [ptlrpc] [13039.348213] ? report_bug+0x113/0x140 [13039.349176] tgt_handle_request0+0x137/0xaf0 [ptlrpc] [13039.350122] ? do_error_trap+0xb6/0x130 [13039.351572] tgt_request_handle+0x575/0x1f70 [ptlrpc] [13039.353160] ? do_invalid_op+0x46/0x60 [13039.355011] ? obd_export_timed_fini+0xc4/0xe0 [obdclass] [13039.356280] ? __debug_object_init.cold.5+0x35/0x15f [13039.357828] ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [13039.359326] ? invalid_op+0x14/0x20 [13039.361081] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [13039.362872] ? __debug_object_init.cold.5+0x35/0x15f [13039.364717] ptlrpc_main+0xce8/0x1400 [ptlrpc] [13039.366256] ? lod_set_pool+0x260/0x260 [lod] [13039.367946] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [13039.369482] debug_object_init+0x22/0x30 [13039.371551] kthread+0x1d1/0x200 [13039.372992] init_timer_key+0x28/0x120 [13039.374976] ? set_kthread_struct+0x70/0x70 [13039.376623] lod_ost_alloc_qos+0x790/0x1c60 [lod] [13039.378219] ret_from_fork+0x1f/0x30 [13039.379230] ? slab_post_alloc_hook+0x66/0x380 [13039.380092] ---[ end trace 8066fd2da60cfde8 ]--- [13039.381207] ? lod_qos_prep_create+0x390/0x1bc0 [lod] [13039.487877] ? __kmalloc+0x1b4/0x4a0 [13039.488697] lod_qos_prep_create+0x134e/0x1bc0 [lod] [13039.489996] ? osd_idc_add.isra.15+0x30/0x520 [osd_zfs] [13039.491624] lod_prepare_create+0x204/0x460 [lod] [13039.493022] lod_declare_striped_create+0x270/0xf80 [lod] [13039.494558] ? lod_sub_declare_create+0x111/0x320 [lod] [13039.496237] lod_declare_create+0x22f/0xb60 [lod] [13039.497551] ? osd_xattr_get+0x2d8/0x8d0 [osd_zfs] [13039.498824] mdd_declare_create_object_internal+0x107/0x4a0 [mdd] [13039.500973] mdd_declare_create_object.isra.25+0x55/0xd30 [mdd] [13039.502691] mdd_declare_create+0x71/0x6d0 [mdd] [13039.503866] ? linkea_add_buf+0xa8/0x4c0 [obdclass] [13039.505329] mdd_create+0x6e3/0x2270 [mdd] [13039.506310] ? mdt_version_save+0xa8/0x210 [mdt] [13039.507660] mdt_reint_open+0x35dd/0x3c80 [mdt] [13039.509058] ? old_init_ucred_common+0x19e/0x820 [mdt] [13039.510483] mdt_reint_rec+0x139/0x2b0 [mdt] [13039.511511] mdt_reint_internal+0x693/0xdc0 [mdt] [13039.512801] mdt_intent_open+0x180/0x5b0 [mdt] [13039.513960] mdt_intent_opc.constprop.43+0x153/0xfb0 [mdt] [13039.515341] ? mdt_intent_fixup_resent+0x2e0/0x2e0 [mdt] [13039.516644] mdt_intent_policy+0x14b/0x670 [mdt] [13039.517801] ldlm_lock_enqueue+0x43c/0xcd0 [ptlrpc] [13039.519321] ? _raw_read_unlock+0x12/0x30 [13039.520547] ? cfs_hash_rw_unlock+0x11/0x30 [obdclass] [13039.521994] ldlm_handle_enqueue+0xcaf/0x2280 [ptlrpc] [13039.523628] tgt_enqueue+0xd0/0x300 [ptlrpc] [13039.524822] tgt_handle_request0+0x137/0xaf0 [ptlrpc] [13039.526605] tgt_request_handle+0x575/0x1f70 [ptlrpc] [13039.528149] ? obd_export_timed_fini+0xc4/0xe0 [obdclass] [13039.529642] ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [13039.531504] ? woken_wake_function+0x30/0x30 [13039.532543] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [13039.534054] ptlrpc_main+0xce8/0x1400 [ptlrpc] [13039.535117] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [13039.536376] kthread+0x1d1/0x200 [13039.537288] ? set_kthread_struct+0x70/0x70 [13039.538427] ret_from_fork+0x1f/0x30 [13039.539351] ---[ end trace 8066fd2da60cfde9 ]--- [13039.595614] ODEBUG: object 000000000192e13c is on stack 000000005786f352, but NOT annotated. [13039.600516] WARNING: CPU: 1 PID: 184286 at lib/debugobjects.c:368 __debug_object_init.cold.5+0x35/0x15f [13039.605721] Modules linked in: lustre(O) osp(O) ofd(O) lod(O) mdt(O) mdd(O) mgs(O) osd_zfs(O) lquota(O) lfsck(O) mgc(O) mdc(O) lov(O) osc(O) lmv(O) fid(O) fld(O) ptlrpc_gss(O) ptlrpc(O) obdclass(O) ksocklnd(O) lnet(O) libcfs(O) ec(O) zfs(O) spl(O) rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver intel_rapl_msr intel_rapl_common sb_edac rapl pcspkr i2c_piix4 squashfs ata_generic crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw ata_piix libata dm_mirror dm_region_hash dm_log dm_mod sha512_ssse3 sha512_generic [last unloaded: obdecho] [13039.628604] CPU: 1 PID: 184286 Comm: mdt00_003 Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [13039.634078] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [13039.635325] ODEBUG: object 00000000476388b2 is on stack 00000000750d757c, but NOT annotated. [13039.638763] RIP: 0010:__debug_object_init.cold.5+0x35/0x15f [13039.641775] WARNING: CPU: 0 PID: 215585 at lib/debugobjects.c:368 __debug_object_init.cold.5+0x35/0x15f [13039.644504] Code: 5e 8f 48 83 05 23 61 0c 03 01 89 05 59 69 0c 03 65 48 8b 04 25 00 dd 01 00 48 8b 50 18 e8 93 68 99 ff 48 83 05 1b 61 0c 03 01 <0f> 0b 48 83 05 19 61 0c 03 01 48 83 05 19 61 0c 03 01 e9 3f ee ff [13039.647671] Modules linked in: lustre(O) osp(O) [13039.657050] RSP: 0018:ffffae18038fb480 EFLAGS: 00010002 [13039.657052] ofd(O) [13039.657061] [13039.658467] lod(O) [13039.660632] RAX: 0000000000000050 RBX: ffffae18038fb588 RCX: 0000000000000000 [13039.661410] mdt(O) [13039.661982] RDX: 0000000000000000 RSI: ffff8f550209e5a8 RDI: ffff8f550209e5a8 [13039.662583] mdd(O) [13039.665201] RBP: ffffffff8fd06ae0 R08: 0000000000000000 R09: c0000000ffff7fff [13039.665942] mgs(O) [13039.668110] R10: 0000000000000001 R11: ffffae18038fb278 R12: ffffffff914f6628 [13039.668713] osd_zfs(O) [13039.671317] R13: 0000000000008e40 R14: ffffffff914f6620 R15: ffff8f550127c028 [13039.671833] lquota(O) [13039.674499] FS: 0000000000000000(0000) GS:ffff8f5502080000(0000) knlGS:0000000000000000 [13039.675204] lfsck(O) [13039.677605] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [13039.678285] mgc(O) [13039.681330] CR2: 00007fa584987000 CR3: 0000000097e16005 CR4: 0000000000170ee0 [13039.681951] mdc(O) [13039.684134] Call Trace: [13039.684829] lov(O) [13039.687142] ? show_regs.cold.9+0x22/0x2f [13039.687599] osc(O) [13039.688865] ? __warn+0xc8/0x150 [13039.689586] lmv(O) [13039.690970] ? __debug_object_init.cold.5+0x35/0x15f [13039.691718] fid(O) [13039.692800] ? report_bug+0x113/0x140 [13039.693512] fld(O) [13039.695127] ? do_error_trap+0xb6/0x130 [13039.695770] ptlrpc_gss(O) [13039.697270] ? do_invalid_op+0x46/0x60 [13039.697724] ptlrpc(O) [13039.698831] ? __debug_object_init.cold.5+0x35/0x15f [13039.699489] obdclass(O) [13039.700554] ? invalid_op+0x14/0x20 [13039.701215] ksocklnd(O) [13039.702644] ? __debug_object_init.cold.5+0x35/0x15f [13039.703470] lnet(O) [13039.704625] ? lod_set_pool+0x260/0x260 [lod] [13039.705291] libcfs(O) [13039.706908] debug_object_init+0x22/0x30 [13039.707285] ec(O) [13039.708826] init_timer_key+0x28/0x120 [13039.709439] zfs(O) [13039.710844] lod_ost_alloc_qos+0x790/0x1c60 [lod] [13039.711635] spl(O) [13039.713175] ? mutex_spin_on_owner+0x7e/0x160 [13039.713783] rpcsec_gss_krb5 [13039.715993] ? __mutex_lock.isra.10+0x315/0xec0 [13039.717013] auth_rpcgss [13039.718677] ? slab_post_alloc_hook+0x66/0x380 [13039.719758] nfsv4 [13039.721589] ? lod_qos_prep_create+0x390/0x1bc0 [lod] [13039.722328] dns_resolver [13039.723758] ? __kmalloc+0x1b4/0x4a0 [13039.724299] intel_rapl_msr [13039.726255] lod_qos_prep_create+0x134e/0x1bc0 [lod] [13039.727076] intel_rapl_common [13039.728457] ? osd_idc_add.isra.15+0x30/0x520 [osd_zfs] [13039.729206] sb_edac [13039.731231] lod_prepare_create+0x204/0x460 [lod] [13039.732416] rapl [13039.734102] lod_declare_striped_create+0x270/0xf80 [lod] [13039.734846] pcspkr [13039.736518] ? lod_sub_declare_create+0x111/0x320 [lod] [13039.737262] i2c_piix4 [13039.739153] lod_declare_create+0x22f/0xb60 [lod] [13039.740068] squashfs [13039.741867] ? osd_xattr_get+0x2d8/0x8d0 [osd_zfs] [13039.742610] ata_generic [13039.744376] mdd_declare_create_object_internal+0x107/0x4a0 [mdd] [13039.745327] crct10dif_pclmul [13039.746690] mdd_declare_create_object.isra.25+0x55/0xd30 [mdd] [13039.747177] crc32_pclmul [13039.748658] mdd_declare_create+0x71/0x6d0 [mdd] [13039.749388] crc32c_intel [13039.751581] ? linkea_add_buf+0xa8/0x4c0 [obdclass] [13039.752204] ghash_clmulni_intel [13039.753896] mdd_create+0x6e3/0x2270 [mdd] [13039.754952] serio_raw [13039.756810] ? mdt_version_save+0xa8/0x210 [mdt] [13039.757605] ata_piix [13039.759069] mdt_reint_open+0x35dd/0x3c80 [mdt] [13039.759905] libata [13039.761928] ? old_init_ucred_common+0x19e/0x820 [mdt] [13039.762662] dm_mirror [13039.764264] mdt_reint_rec+0x139/0x2b0 [mdt] [13039.764959] dm_region_hash [13039.766616] mdt_reint_internal+0x693/0xdc0 [mdt] [13039.767314] dm_log [13039.768204] mdt_intent_open+0x180/0x5b0 [mdt] [13039.769041] dm_mod [13039.770376] mdt_intent_opc.constprop.43+0x153/0xfb0 [mdt] [13039.771116] sha512_ssse3 [13039.773232] ? mdt_intent_fixup_resent+0x2e0/0x2e0 [mdt] [13039.773875] sha512_generic [13039.776269] mdt_intent_policy+0x14b/0x670 [mdt] [13039.776942] [last unloaded: obdecho] [13039.779205] ldlm_lock_enqueue+0x43c/0xcd0 [ptlrpc] [13039.780229] [13039.781671] ? _raw_read_unlock+0x12/0x30 [13039.783026] CPU: 0 PID: 215585 Comm: mdt00_007 Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [13039.784576] ? cfs_hash_rw_unlock+0x11/0x30 [obdclass] [13039.785299] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [13039.786561] ldlm_handle_enqueue+0xcaf/0x2280 [ptlrpc] [13039.790012] RIP: 0010:__debug_object_init.cold.5+0x35/0x15f [13039.791730] tgt_enqueue+0xd0/0x300 [ptlrpc] [13039.794384] Code: 5e 8f 48 83 05 23 61 0c 03 01 89 05 59 69 0c 03 65 48 8b 04 25 00 dd 01 00 48 8b 50 18 e8 93 68 99 ff 48 83 05 1b 61 0c 03 01 <0f> 0b 48 83 05 19 61 0c 03 01 48 83 05 19 61 0c 03 01 e9 3f ee ff [13039.796363] tgt_handle_request0+0x137/0xaf0 [ptlrpc] [13039.798210] RSP: 0018:ffffae1802fb3480 EFLAGS: 00010006 [13039.799755] tgt_request_handle+0x575/0x1f70 [ptlrpc] [13039.805163] [13039.806916] ? obd_export_timed_fini+0xc4/0xe0 [obdclass] [13039.808831] RAX: 0000000000000050 RBX: ffffae1802fb3588 RCX: 0000000000000000 [13039.810601] ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [13039.811119] RDX: 0000000000000000 RSI: ffff8f550201e5a8 RDI: ffff8f550201e5a8 [13039.813082] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [13039.815158] RBP: ffffffff8fd06ae0 R08: 30207463656a626f R09: 203a47554245444f [13039.817268] ptlrpc_main+0xce8/0x1400 [ptlrpc] [13039.819452] R10: 30207463656a626f R11: 203a47554245444f R12: ffffffff9152fd28 [13039.821348] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [13039.823161] R13: 0000000000042540 R14: ffffffff9152fd20 R15: ffff8f54ea4e3f28 [13039.824442] kthread+0x1d1/0x200 [13039.826631] FS: 0000000000000000(0000) GS:ffff8f5502000000(0000) knlGS:0000000000000000 [13039.828777] ? set_kthread_struct+0x70/0x70 [13039.831140] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [13039.832365] ret_from_fork+0x1f/0x30 [13039.833828] CR2: 00007fa5885c00a0 CR3: 0000000097e16001 CR4: 0000000000170ef0 [13039.834895] ---[ end trace 8066fd2da60cfdea ]--- [13039.836865] Call Trace: [13039.842683] ? show_regs.cold.9+0x22/0x2f [13039.843670] ? __warn+0xc8/0x150 [13039.844345] ? __debug_object_init.cold.5+0x35/0x15f [13039.845663] ? report_bug+0x113/0x140 [13039.846764] ? do_error_trap+0xb6/0x130 [13039.847769] ? do_invalid_op+0x46/0x60 [13039.848946] ? __debug_object_init.cold.5+0x35/0x15f [13039.850622] ? invalid_op+0x14/0x20 [13039.851828] ? __debug_object_init.cold.5+0x35/0x15f [13039.853343] ? lod_set_pool+0x260/0x260 [lod] [13039.854532] debug_object_init+0x22/0x30 [13039.856083] init_timer_key+0x28/0x120 [13039.856998] lod_ost_alloc_qos+0x790/0x1c60 [lod] [13039.858589] ? slab_post_alloc_hook+0x66/0x380 [13039.859974] ? lod_qos_prep_create+0x390/0x1bc0 [lod] [13039.861670] ? __kmalloc+0x1b4/0x4a0 [13039.862816] lod_qos_prep_create+0x134e/0x1bc0 [lod] [13039.864359] ? osd_idc_add.isra.15+0x30/0x520 [osd_zfs] [13039.865893] lod_prepare_create+0x204/0x460 [lod] [13039.867121] lod_declare_striped_create+0x270/0xf80 [lod] [13039.868802] ? lod_sub_declare_create+0x111/0x320 [lod] [13039.870064] lod_declare_create+0x22f/0xb60 [lod] [13039.871756] ? osd_xattr_get+0x2d8/0x8d0 [osd_zfs] [13039.873052] mdd_declare_create_object_internal+0x107/0x4a0 [mdd] [13039.875100] mdd_declare_create_object.isra.25+0x55/0xd30 [mdd] [13039.876490] mdd_declare_create+0x71/0x6d0 [mdd] [13039.877908] ? linkea_add_buf+0xa8/0x4c0 [obdclass] [13039.879849] mdd_create+0x6e3/0x2270 [mdd] [13039.881030] ? mdt_version_save+0xa8/0x210 [mdt] [13039.882256] mdt_reint_open+0x35dd/0x3c80 [mdt] [13039.883997] ? old_init_ucred_common+0x19e/0x820 [mdt] [13039.885517] mdt_reint_rec+0x139/0x2b0 [mdt] [13039.886813] mdt_reint_internal+0x693/0xdc0 [mdt] [13039.888082] mdt_intent_open+0x180/0x5b0 [mdt] [13039.889378] mdt_intent_opc.constprop.43+0x153/0xfb0 [mdt] [13039.890886] ? mdt_intent_fixup_resent+0x2e0/0x2e0 [mdt] [13039.892306] mdt_intent_policy+0x14b/0x670 [mdt] [13039.893595] ldlm_lock_enqueue+0x43c/0xcd0 [ptlrpc] [13039.895185] ? _raw_read_unlock+0x12/0x30 [13039.896303] ? cfs_hash_rw_unlock+0x11/0x30 [obdclass] [13039.897889] ldlm_handle_enqueue+0xcaf/0x2280 [ptlrpc] [13039.899568] tgt_enqueue+0xd0/0x300 [ptlrpc] [13039.900631] tgt_handle_request0+0x137/0xaf0 [ptlrpc] [13039.902467] tgt_request_handle+0x575/0x1f70 [ptlrpc] [13039.904333] ? obd_export_timed_fini+0xc4/0xe0 [obdclass] [13039.906146] ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [13039.908113] ? woken_wake_function+0x30/0x30 [13039.909386] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [13039.911131] ptlrpc_main+0xce8/0x1400 [ptlrpc] [13039.912711] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [13039.914334] kthread+0x1d1/0x200 [13039.915183] ? set_kthread_struct+0x70/0x70 [13039.916210] ret_from_fork+0x1f/0x30 [13039.917323] ---[ end trace 8066fd2da60cfdeb ]--- [13084.917834] Lustre: DEBUG MARKER: == sanity test 182b: Test parallel modify metadata operations from osp ========================================================== 08:52:22 (1778935942) [13085.801783] Lustre: DEBUG MARKER: SKIP: sanity test_182b needs >= 2 MDTs [13086.790441] Lustre: DEBUG MARKER: == sanity test 183: No crash or request leak in case of strange dispositions ================================================================== 08:52:24 (1778935944) [13087.532245] Lustre: *** cfs_fail_loc=148, val=0*** [13091.518078] Lustre: DEBUG MARKER: == sanity test 184a: Basic layout swap =================== 08:52:29 (1778935949) [13097.319451] Lustre: DEBUG MARKER: == sanity test 184b: Forbidden layout swap (will generate errors) ========================================================== 08:52:35 (1778935955) [13101.372117] Lustre: DEBUG MARKER: == sanity test 184c: Concurrent write and layout swap ==== 08:52:39 (1778935959) [13116.493274] Lustre: DEBUG MARKER: == sanity test 184d: allow stripeless layouts swap ======= 08:52:54 (1778935974) [13121.835637] Lustre: DEBUG MARKER: == sanity test 184e: Recreate layout after stripeless layout swaps ========================================================== 08:52:59 (1778935979) [13126.714558] Lustre: DEBUG MARKER: == sanity test 184f: IOC_MDC_GETFILEINFO for files with long names but no striping ========================================================== 08:53:04 (1778935984) [13130.350425] Lustre: DEBUG MARKER: == sanity test 185: Volatile file support ================ 08:53:08 (1778935988) [13135.046370] Lustre: DEBUG MARKER: == sanity test 185a: Volatile file creation in .lustre/fid/ ========================================================== 08:53:13 (1778935993) [13140.814109] Lustre: DEBUG MARKER: == sanity test 187a: Test data version change ============ 08:53:18 (1778935998) [13145.728258] Lustre: DEBUG MARKER: == sanity test 187b: Test data version change on volatile file ========================================================== 08:53:23 (1778936003) [13149.631027] Lustre: DEBUG MARKER: == sanity test 190a: check lfs project -p works with project name ========================================================== 08:53:27 (1778936007) [13153.360614] Lustre: DEBUG MARKER: == sanity test 190b: check lfs find --project works with project name ========================================================== 08:53:31 (1778936011) [13167.952500] Lustre: DEBUG MARKER: == sanity test 190c: check lfs project -p works with u:USERNAME ========================================================== 08:53:45 (1778936025) [13176.450430] Lustre: DEBUG MARKER: == sanity test complete, duration 12883 sec ============== 08:53:54 (1778936034) [13177.417644] Lustre: DEBUG MARKER: === sanity: start cleanup 08:53:55 (1778936035) === [13198.927693] Lustre: DEBUG MARKER: === sanity: finish cleanup 08:54:16 (1778936056) === [13201.379667] 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 [13201.381566] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13201.388165] Lustre: Skipped 1 previous similar message [13201.392349] Lustre: Skipped 1 previous similar message [13206.628935] Lustre: server umount lustre-MDT0000 complete [13208.757875] LustreError: 109283:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1778936067 with bad export cookie 10054302611672378496 [13208.762753] LustreError: MGC192.168.204.101@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13208.765868] LustreError: 109283:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [13208.915326] Lustre: server umount lustre-OST0000 complete [13211.067998] Lustre: server umount lustre-OST0001 complete [13216.839276] Lustre: DEBUG MARKER: oleg401-server.virtnet: executing unload_modules_local [13218.288522] Key type lgssc unregistered [13218.451635] LNet: 222303:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [13218.456871] LNetError: 222303:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [13218.468585] LNet: Removed LNI 192.168.204.101@tcp [13218.906205] Key type .llcrypt unregistered [13218.908591] Key type ._llcrypt unregistered