[ 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 647393514 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.001010] APIC: Switch to symmetric I/O mode setup [ 0.003217] x2apic enabled [ 0.004006] Switched APIC routing to physical x2apic. [ 0.005014] kvm-guest: setup PV IPIs [ 0.008000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 0.008019] Calibrating delay loop (skipped) preset value.. 4800.00 BogoMIPS (lpj=2400000) [ 0.009012] pid_max: default: 32768 minimum: 301 [ 0.010148] LSM: Security Framework initializing [ 0.012086] Yama: becoming mindful. [ 0.013072] SELinux: Initializing. [ 0.015069] *** VALIDATE selinux *** [ 0.033439] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.039439] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.040156] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.041129] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.042131] *** VALIDATE tmpfs *** [ 0.044427] *** VALIDATE proc *** [ 0.045388] *** VALIDATE cgroup *** [ 0.046000] *** VALIDATE cgroup2 *** [ 0.047092] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.049017] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.050012] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.051036] Spectre V2 : User space: Vulnerable [ 0.052013] Speculative Store Bypass: Vulnerable [ 0.056209] debug: unmapping init [mem 0xffffffffb6659000-0xffffffffb6660fff] [ 0.059975] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.062406] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.063043] ... version: 2 [ 0.064030] ... bit width: 48 [ 0.065015] ... generic registers: 4 [ 0.066025] ... value mask: 0000ffffffffffff [ 0.067020] ... max period: 00007fffffffffff [ 0.068031] ... fixed-purpose events: 3 [ 0.069021] ... event mask: 000000070000000f [ 0.070832] rcu: Hierarchical SRCU implementation. [ 0.074042] smp: Bringing up secondary CPUs ... [ 0.076211] x86: Booting SMP configuration: [ 0.077452] .... node #0, CPUs: #1 #2 #3 [ 0.098015] smp: Brought up 1 node, 4 CPUs [ 0.100015] smpboot: Max logical packages: 1 [ 0.101016] smpboot: Total of 4 processors activated (19200.00 BogoMIPS) [ 0.173363] node 0 deferred pages initialised in 68ms [ 0.187158] devtmpfs: initialized [ 0.190570] x86/mm: Memory block size: 128MB [ 0.195780] gcov: version magic: 0x41383552 [ 0.198719] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.199083] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.203434] pinctrl core: initialized pinctrl subsystem [ 0.207717] [ 0.209008] ************************************************************* [ 0.216053] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.222014] ** ** [ 0.228014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.234022] ** ** [ 0.243014] ** This means that this kernel is built to expose internal ** [ 0.258026] ** IOMMU data structures, which may compromise security on ** [ 0.273021] ** your system. ** [ 0.285013] ** ** [ 0.288011] ** If you see this message and you are not debugging the ** [ 0.290011] ** kernel, report this immediately to your vendor! ** [ 0.293011] ** ** [ 0.296012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.298010] ************************************************************* [ 0.301654] NET: Registered protocol family 16 [ 0.304436] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.315096] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.330098] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.333647] cpuidle: using governor menu [ 0.338652] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.342796] PCI: Using configuration type 1 for base access [ 0.346313] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.358475] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.359218] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.364086] cryptd: max_cpu_qlen set to 1000 [ 0.367243] ACPI: Added _OSI(Module Device) [ 0.368000] ACPI: Added _OSI(Processor Device) [ 0.368014] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.370023] ACPI: Added _OSI(Processor Aggregator Device) [ 0.377151] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.385617] ACPI: Interpreter enabled [ 0.388074] ACPI: PM: (supports S0 S3 S4 S5) [ 0.390069] ACPI: Using IOAPIC for interrupt routing [ 0.392115] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.396599] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.426444] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.437071] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.463025] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.486120] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.533517] acpiphp: Slot [2] registered [ 0.555806] acpiphp: Slot [5] registered [ 0.561141] acpiphp: Slot [6] registered [ 0.565518] acpiphp: Slot [7] registered [ 0.571520] acpiphp: Slot [8] registered [ 0.576143] acpiphp: Slot [9] registered [ 0.580195] acpiphp: Slot [10] registered [ 0.584138] acpiphp: Slot [3] registered [ 0.588237] acpiphp: Slot [4] registered [ 0.591172] acpiphp: Slot [11] registered [ 0.596147] acpiphp: Slot [12] registered [ 0.601317] acpiphp: Slot [13] registered [ 0.606123] acpiphp: Slot [14] registered [ 0.608125] acpiphp: Slot [15] registered [ 0.616448] acpiphp: Slot [16] registered [ 0.622201] acpiphp: Slot [17] registered [ 0.627980] acpiphp: Slot [18] registered [ 0.632210] acpiphp: Slot [19] registered [ 0.642268] acpiphp: Slot [20] registered [ 0.649364] acpiphp: Slot [21] registered [ 0.656270] acpiphp: Slot [22] registered [ 0.669000] acpiphp: Slot [23] registered [ 0.681127] acpiphp: Slot [24] registered [ 0.690474] acpiphp: Slot [25] registered [ 0.699100] acpiphp: Slot [26] registered [ 0.707276] acpiphp: Slot [27] registered [ 0.715151] acpiphp: Slot [28] registered [ 0.721512] acpiphp: Slot [29] registered [ 0.727155] acpiphp: Slot [30] registered [ 0.733252] acpiphp: Slot [31] registered [ 0.738105] PCI host bridge to bus 0000:00 [ 0.743031] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.747026] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.755048] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.766050] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.772059] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.777051] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.781122] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.784543] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.789793] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.806015] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.812155] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.818025] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.820016] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.824027] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.828788] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.833461] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.838066] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.844109] pci 0000:00:01.3: quirk_piix4_acpi+0x0/0x1e0 took 11718 usecs [ 0.860084] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.877016] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.894016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.904017] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.912718] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.928014] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.943017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 1.014017] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 1.032239] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 1.046014] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 1.055031] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 1.081028] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 1.098516] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 1.110042] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 1.119014] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 1.134023] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 1.146991] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 1.157020] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 1.163014] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 1.192020] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 1.219081] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 1.231026] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 1.244024] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 1.261017] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 1.432265] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 1.443035] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 1.451016] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 1.478018] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 1.495930] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 1.512095] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 1.521028] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 1.528961] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 1.534263] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 1.929140] iommu: Default domain type: Passthrough [ 1.931667] SCSI subsystem initialized [ 1.932222] ACPI: bus type USB registered [ 1.933123] usbcore: registered new interface driver usbfs [ 1.934212] usbcore: registered new interface driver hub [ 1.938073] usbcore: registered new device driver usb [ 1.939206] pps_core: LinuxPPS API ver. 1 registered [ 1.942016] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 1.946086] PTP clock support registered [ 1.949064] EDAC MC: Ver: 3.0.0 [ 1.951213] PCI: Using ACPI for IRQ routing [ 1.954425] NetLabel: Initializing [ 1.956017] NetLabel: domain hash size = 128 [ 1.958019] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 1.960093] NetLabel: unlabeled traffic allowed by default [ 1.963489] vgaarb: loaded [ 1.965361] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.966014] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.970453] clocksource: Switched to clocksource kvm-clock [ 2.138564] VFS: Disk quotas dquot_6.6.0 [ 2.140865] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 2.144562] *** VALIDATE ramfs *** [ 2.146462] *** VALIDATE hugetlbfs *** [ 2.148813] pnp: PnP ACPI init [ 2.152336] pnp: PnP ACPI: found 6 devices [ 2.171893] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 2.183864] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 2.191323] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 2.200280] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 2.208850] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 2.216615] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 2.226058] NET: Registered protocol family 2 [ 2.235739] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 2.250996] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 2.263946] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 2.285673] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 2.299719] TCP: Hash tables configured (established 65536 bind 65536) [ 2.309549] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 2.319497] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 2.326988] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 2.333627] NET: Registered protocol family 1 [ 2.341584] RPC: Registered named UNIX socket transport module. [ 2.346892] RPC: Registered udp transport module. [ 2.350435] RPC: Registered tcp transport module. [ 2.355343] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 2.360758] NET: Registered protocol family 44 [ 2.363379] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 2.370762] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 2.375315] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 2.386424] PCI: CLS 0 bytes, default 64 [ 2.392996] Unpacking initramfs... [ 5.420291] debug: unmapping init [mem 0xffff94b03cc54000-0xffff94b03ffbffff] [ 5.425126] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 5.427806] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 5.430954] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 6.193252] Initialise system trusted keyrings [ 6.197459] Key type blacklist registered [ 6.222285] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 6.244436] zbud: loaded [ 6.249252] *** VALIDATE nfs *** [ 6.250698] *** VALIDATE nfs4 *** [ 6.252735] pstore: using deflate compression [ 6.258704] Platform Keyring initialized [ 6.418028] NET: Registered protocol family 38 [ 6.419752] Key type asymmetric registered [ 6.421864] Asymmetric key parser 'x509' registered [ 6.424256] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 6.427826] io scheduler mq-deadline registered [ 6.429745] io scheduler kyber registered [ 6.431659] io scheduler bfq registered [ 6.433678] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 6.436989] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 6.440377] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 6.443942] ACPI: Power Button [PWRF] [ 6.451519] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 6.463639] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 6.511976] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 6.526156] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 6.553562] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 6.584194] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 6.614709] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 6.620545] Non-volatile memory driver v1.3 [ 6.626168] Linux agpgart interface v0.103 [ 6.677575] virtio_blk virtio1: [vda] 68288 512-byte logical blocks (35.0 MB/33.3 MiB) [ 6.681251] vda: detected capacity change from 0 to 34963456 [ 6.752228] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 6.756150] vdb: detected capacity change from 0 to 1073741824 [ 6.789872] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 6.794652] vdc: detected capacity change from 0 to 2621440000 [ 6.814774] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 6.818769] vdd: detected capacity change from 0 to 2621440000 [ 6.842667] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 6.847174] vde: detected capacity change from 0 to 4294967296 [ 6.882600] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 6.885892] vdf: detected capacity change from 0 to 4294967296 [ 6.896254] libphy: Fixed MDIO Bus: probed [ 6.902361] usbcore: registered new interface driver usbserial_generic [ 6.905287] usbserial: USB Serial support registered for generic [ 6.907856] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 6.913712] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 6.915902] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 6.918887] mousedev: PS/2 mouse device common for all mice [ 6.923429] rtc_cmos 00:05: RTC can wake from S4 [ 6.927249] rtc_cmos 00:05: registered as rtc0 [ 6.929403] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 6.933167] intel_pstate: CPU model not supported [ 6.937378] hid: raw HID events driver (C) Jiri Kosina [ 6.940531] usbcore: registered new interface driver usbhid [ 6.942493] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 6.944649] usbhid: USB HID core driver [ 6.945651] drop_monitor: Initializing network drop monitor service [ 6.957413] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 6.962516] Initializing XFRM netlink socket [ 6.968173] NET: Registered protocol family 10 [ 6.975923] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 6.995509] Segment Routing with IPv6 [ 6.999144] NET: Registered protocol family 17 [ 7.004908] mpls_gso: MPLS GSO support [ 7.013780] RAS: Correctable Errors collector initialized. [ 7.036889] AVX version of gcm_enc/dec engaged. [ 7.039731] AES CTR mode by8 optimization enabled [ 7.292822] sched_clock: Marking stable (7292803334, 0)->(10096562124, -2803758790) [ 7.295814] registered taskstats version 1 [ 7.302933] Loading compiled-in X.509 certificates [ 7.304989] zswap: loaded using pool lzo/zbud [ 7.516455] Key type big_key registered [ 7.530629] Key type encrypted registered [ 7.532542] ima: No TPM chip found, activating TPM-bypass! [ 7.535284] ima: Allocated hash algorithm: sha1 [ 7.537179] ima: No architecture policies found [ 7.539622] evm: Initialising EVM extended attributes: [ 7.541640] evm: security.selinux [ 7.543223] evm: security.ima [ 7.548290] evm: security.capability [ 7.555034] evm: HMAC attrs: 0x1 [ 7.565545] rtc_cmos 00:05: setting system clock to 2026-05-11 21:23:08 UTC (1778534588) [ 7.581427] debug: unmapping init [mem 0xffffffffb7603000-0xffffffffb77fffff] [ 7.587619] debug: unmapping init [mem 0xffffffffb6382000-0xffffffffb6658fff] [ 7.599103] Write protecting the kernel read-only data: 28672k [ 7.606959] debug: unmapping init [mem 0xffffffffb4a03000-0xffffffffb4bfffff] [ 7.611633] debug: unmapping init [mem 0xffffffffb5314000-0xffffffffb53fffff] [ 7.657733] 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) [ 7.666980] systemd[1]: Detected virtualization kvm. [ 7.669439] systemd[1]: Detected architecture x86-64. [ 7.671776] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 7.701284] systemd[1]: No hostname configured. [ 7.702506] systemd[1]: Set hostname to . [ 7.705252] random: systemd: uninitialized urandom read (16 bytes read) [ 7.708285] systemd[1]: Initializing machine ID from random generator. [ 8.030425] random: ln: uninitialized urandom read (6 bytes read) [ 8.181870] hrtimer: interrupt took 15873621 ns [ 8.399464] random: systemd: uninitialized urandom read (16 bytes read) [ 8.403770] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 8.439545] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 8.473555] systemd[1]: Started Memstrack Anylazing Service. [ OK ] Started Memstrack Anylazing Service. Starting Setup Virtual Console... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Initrd Root Device. Starting Journal Service... [ OK ] Reached target Timers. [ OK ] Reached target Slices. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Swap. [ OK ] Reached target Paths. Starting Apply Kernel Variables... [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 13.932714] device-mapper: uevent: version 1.0.3 [ 13.946904] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 17.675503] virtio_net virtio0 ens2: renamed from eth0 [ 17.926011] random: fast init done [ 18.151715] scsi host0: ata_piix [ 18.192507] scsi host1: ata_piix [ 18.197193] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 18.202627] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 24.078162] random: crng init done [ 24.083544] random: 7 urandom warning(s) missed due to ratelimiting [ 26.540092] dracut-initqueue[580]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 29.200239] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Timers. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ 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 Swap. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 33.980252] printk: systemd: 26 output lines suppressed due to ratelimiting [ 34.976536] SELinux: Disabled at runtime. [ 35.169959] 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) [ 35.199651] systemd[1]: Detected virtualization kvm. [ 35.221155] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 37.803781] systemd[1]: initrd-switch-root.service: Succeeded. [ 37.814566] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 37.838947] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 37.852919] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 37.860623] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 37.886891] systemd[1]: Starting Journal Service... Starting Journal Service... [ 37.899731] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on initctl Compatibility Named Pipe. Starting Remount Root and Kernel File Systems... Mounting Kernel Debug File System... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Created slice system-serial\x2dgetty.slice. Mounting Huge Pages File System... [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Created slice system-getty.slice. [ OK ] Listening on udev Control Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Starting Apply Kernel Variables... [ OK ] Reached target Paths. Mounting POSIX Message Queue File System... [ OK ] Stopped target Initrd Root File System. [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Created slice system-sshd\x2dkeygen.slice. Activating swap /dev/disk/by-label/SWAP... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [FAILED] Failed to start Remount Root and Kernel File Systems. [ 38.646316] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Huge Pages File System. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started 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 /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 39.696983] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 41.183193] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 41.230364] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 42.955149] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 43.161730] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit) [** ] A start job is running for Configur…-only root support (8s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] 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) [ ***] A start job is running for Configur…only root support (10s / no limit)[ 48.793921] Key type dns_resolver registered [ **] A start job is running for Configur…only root support (11s / no limit) [ *] 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) [ ***] A start job is running for Configur…only root support (12s / no limit)[ 50.624410] NFS: Registering the id_resolver key type [ 50.626293] Key type id_resolver registered [ 50.639327] Key type id_legacy registered [ *** ] A start job is running for Configur…only root support (13s / no limit) [ *** ] A start job is running for Configur…only root support (13s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Rebuild Dynamic Linker Cache... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Login Service. [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg420-server login: [ 87.785892] spl: loading out-of-tree module taints kernel. [ 90.015144] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 97.499113] alg: No test for adler32 (adler32-zlib) [ 98.252426] Key type ._llcrypt registered [ 98.254219] Key type .llcrypt registered [ 98.314728] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing set_hostid [ 109.339655] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 110.274813] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 110.707704] Lustre: Lustre: Build Version: 2.15.8_3_g9d40529 [ 111.311118] LNet: Added LNI 192.168.204.120@tcp [8/256/0/180] [ 111.314465] LNet: Accept secure, port 988 [ 112.967108] Key type lgssc registered [ 114.106274] Lustre: Echo OBD driver; http://www.lustre.org/ [ 121.556314] vdc: vdc1 vdc9 [ 128.140352] vde: vde1 vde9 [ 135.030680] vdf: vdf1 vdf9 [ 147.356513] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 154.125218] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall in log lustre-MDT0000 [ 154.390620] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space: rc = -61 [ 154.452592] Lustre: lustre-MDT0000: new disk, initializing [ 154.709791] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 154.750291] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 157.566278] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 164.046861] Lustre: lustre-OST0000: new disk, initializing [ 164.050072] Lustre: srv-lustre-OST0000: No data found on store. Initialize space: rc = -61 [ 164.058807] Lustre: Skipped 1 previous similar message [ 164.128657] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 167.242811] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 173.764321] Lustre: lustre-OST0001: new disk, initializing [ 173.768877] Lustre: srv-lustre-OST0001: No data found on store. Initialize space: rc = -61 [ 173.842991] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 176.688519] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 184.172440] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 190.163824] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 197.970369] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing check_logdir /tmp/testlogs/ [ 201.697883] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing yml_node [ 204.388583] Lustre: DEBUG MARKER: Client: 2.15.8.3 [ 205.663758] Lustre: DEBUG MARKER: MDS: 2.15.8.3 [ 206.961266] Lustre: DEBUG MARKER: OSS: 2.15.8.3 [ 207.780881] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Mon May 11 17:26:28 EDT 2026 [ 212.458899] Lustre: DEBUG MARKER: excepting tests: 27 28 102 [ 213.420944] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 217.933472] Lustre: DEBUG MARKER: oleg420-client.virtnet: executing check_config_client /mnt/lustre [ 230.219461] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 232.688597] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 235.449491] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all 8 [ 237.037392] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 17:26:57 (1778534817) [ 241.311355] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 17:27:01 (1778534821) [ 245.122984] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 17:27:05 (1778534825) [ 249.551388] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 17:27:09 (1778534829) [ 253.724634] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 17:27:14 (1778534834) [ 257.489946] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 17:27:17 (1778534837) [ 261.306578] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 17:27:21 (1778534841) [ 262.216948] Lustre: DEBUG MARKER: SKIP: sanityn test_2f needs >= 2 MDTs [ 263.285459] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 17:27:23 (1778534843) [ 267.466679] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 17:27:27 (1778534847) [ 271.306380] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 17:27:31 (1778534851) [ 276.312721] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 17:27:36 (1778534856) [ 280.176547] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 17:27:40 (1778534860) [ 284.851760] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 17:27:45 (1778534865) [ 289.125651] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 17:27:49 (1778534869) [ 293.488329] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 17:27:53 (1778534873) [ 298.149879] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 17:27:58 (1778534878) [ 302.525773] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 17:28:02 (1778534882) [ 307.343746] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 17:28:07 (1778534887) [ 311.475464] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 17:28:11 (1778534891) [ 316.065810] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 17:28:16 (1778534896) [ 455.979639] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 17:30:36 (1778535036) [ 460.700604] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 17:30:41 (1778535041) [ 464.198320] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 17:30:44 (1778535044) [ 467.754329] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 17:30:48 (1778535048) [ 471.247805] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 17:30:51 (1778535051) [ 474.670739] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 17:30:55 (1778535055) [ 475.661362] Lustre: DEBUG MARKER: chmod [ 479.005304] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 17:30:59 (1778535059) [ 483.089943] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7519232kB free gt MAXFREE 800000kB, increase 800000 (or reduce test fs size) to proceed [ 494.109828] Lustre: DEBUG MARKER: == sanityn test 16a: 500 iterations of dual-mount fsx ==== 17:31:14 (1778535074) [ 532.719885] Lustre: DEBUG MARKER: == sanityn test 16b: 500 iterations of dual-mount fsx at small size ========================================================== 17:31:53 (1778535113) [ 553.006733] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 17:32:13 (1778535133) [ 554.467669] Lustre: DEBUG MARKER: SKIP: sanityn test_16c dio on ldiskfs only [ 555.579284] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 17:32:15 (1778535135) [ 581.487367] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 17:32:41 (1778535161) [ 585.324215] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 17:32:45 (1778535165) [ 609.142755] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 17:33:09 (1778535189) [ 633.057327] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 17:33:33 (1778535213) [ 636.456817] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 17:33:36 (1778535216) [ 637.169247] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 30a sleeping for 2000ms [ 639.255122] LustreError: 5514:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 30a awake [ 642.128186] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 17:33:42 (1778535222) [ 661.571259] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 17:34:02 (1778535242) [ 662.764302] Lustre: DEBUG MARKER: SKIP: sanityn test_19 not cache-capable obdfilter [ 663.503699] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 17:34:04 (1778535244) [ 666.316812] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 17:34:06 (1778535246) [ 669.123388] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 17:34:09 (1778535249) [ 734.290107] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 17:35:14 (1778535314) [ 738.154248] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 17:35:18 (1778535318) [ 741.784277] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 17:35:22 (1778535322) [ 745.476541] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 17:35:25 (1778535325) [ 746.295365] Lustre: DEBUG MARKER: SKIP: sanityn test_25b needs >= 2 MDTs [ 747.277321] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 17:35:27 (1778535327) [ 752.370401] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 17:35:32 (1778535332) [ 758.746812] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 759.646351] Lustre: DEBUG MARKER: SKIP: sanityn test_28 skipping ALWAYS excluded test 28 [ 760.486742] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 17:35:40 (1778535340) [ 766.662478] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 17:35:46 (1778535346) [ 771.382160] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 17:35:51 (1778535351) [ 782.453334] Lustre: *** cfs_fail_loc=316, val=0*** [ 786.491361] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 17:36:06 (1778535366) [ 793.704402] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 794.733341] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 17:36:15 (1778535375) [ 795.774553] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 796.831717] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-Lock-Cancel ========================================================== 17:36:17 (1778535377) [ 797.668523] Lustre: DEBUG MARKER: SKIP: sanityn test_33c needs >= 2 MDTs [ 798.666479] Lustre: DEBUG MARKER: == sanityn test 33d: DNE distributed operation should trigger COS ========================================================== 17:36:19 (1778535379) [ 799.475660] Lustre: DEBUG MARKER: SKIP: sanityn test_33d needs >= 2 MDTs [ 800.452877] Lustre: DEBUG MARKER: == sanityn test 33e: DNE local operation shouldn't trigger COS ========================================================== 17:36:20 (1778535380) [ 801.321553] Lustre: DEBUG MARKER: SKIP: sanityn test_33e Need two or more clients, have 1 [ 802.178145] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 17:36:22 (1778535382) [ 803.974675] Lustre: *** cfs_fail_loc=512, val=0*** [ 803.976614] LustreError: 5513:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 sleeping for 4000ms [ 805.344244] Lustre: *** cfs_fail_loc=512, val=0*** [ 805.344326] LustreError: 14221:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 sleeping for 4000ms [ 805.347203] Lustre: Skipped 6 previous similar messages [ 805.351568] LustreError: 14221:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 807.890612] Lustre: *** cfs_fail_loc=512, val=0*** [ 807.892464] LustreError: 14236:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 sleeping for 4000ms [ 807.905391] LustreError: 14236:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 4 previous similar messages [ 808.039130] LustreError: 5513:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 awake [ 809.399125] LustreError: 6312:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 awake [ 809.399125] LustreError: 9464:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 awake [ 809.403817] LustreError: 6312:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 809.416018] LustreError: 9464:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 810.463455] Lustre: *** cfs_fail_loc=512, val=0*** [ 810.466917] Lustre: Skipped 17 previous similar messages [ 811.951140] LustreError: 22195:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 awake [ 811.955283] LustreError: 22195:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 812.145592] Lustre: *** cfs_fail_loc=512, val=0*** [ 812.152369] LustreError: 6326:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 sleeping for 4000ms [ 812.158538] LustreError: 6326:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 8 previous similar messages [ 813.151395] Lustre: *** cfs_fail_loc=512, val=0*** [ 814.176111] Lustre: *** cfs_fail_loc=512, val=0*** [ 815.583602] Lustre: *** cfs_fail_loc=512, val=0*** [ 815.589339] Lustre: Skipped 13 previous similar messages [ 816.224394] LustreError: 6326:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 awake [ 816.225066] Lustre: *** cfs_fail_loc=512, val=0*** [ 816.232309] LustreError: 6326:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 9 previous similar messages [ 816.235397] Lustre: Skipped 1 previous similar message [ 820.319857] LustreError: 16314:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 sleeping for 4000ms [ 820.324727] LustreError: 16314:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 14 previous similar messages [ 823.775763] Lustre: *** cfs_fail_loc=512, val=0*** [ 823.778708] Lustre: Skipped 24 previous similar messages [ 824.383122] LustreError: 16314:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 512 awake [ 824.392821] LustreError: 16314:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 11 previous similar messages [ 833.391591] Lustre: *** cfs_fail_loc=512, val=0*** [ 838.607167] LustreError: 5513:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 511 sleeping for 4000ms [ 838.611279] LustreError: 5513:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 40 previous similar messages [ 840.735297] LustreError: 5502:0:(ldlm_lockd.c:261:expired_lock_main()) ### lock callback timer expired after 1s: evicting client at 192.168.204.20@tcp ns: filter-lustre-OST0000_UUID lock: 000000001a43c8a6/0x819348c5c4a1b8ed lrc: 3/0,0 mode: PR/PR res: [0x27:0x0:0x0].0x0 rrc: 4 type: EXT [0->18446744073709551615] (req 0->4095) gid 0 flags: 0x60000400030020 nid: 192.168.204.20@tcp remote: 0xf5636d25a8e04997 expref: 9 pid: 6311 timeout: 840 lvb_type: 0 [ 841.184173] Lustre: *** cfs_fail_loc=511, val=0*** [ 841.187179] Lustre: Skipped 54 previous similar messages [ 842.663128] LustreError: 6312:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 511 awake [ 842.663128] LustreError: 6309:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 511 awake [ 842.663142] LustreError: 6312:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 33 previous similar messages [ 842.672051] LustreError: 6309:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 34 previous similar messages [ 847.221218] Lustre: *** cfs_fail_loc=511, val=0*** [ 847.224031] Lustre: Skipped 7 previous similar messages [ 848.223140] LustreError: 5502:0:(ldlm_lockd.c:261:expired_lock_main()) ### lock callback timer expired after 1s: evicting client at 192.168.204.20@tcp ns: filter-lustre-OST0001_UUID lock: 000000001e8dbee3/0x819348c5c4a1b95d lrc: 3/0,0 mode: PW/PW res: [0x23:0x0:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->4095) gid 0 flags: 0x60000400000020 nid: 192.168.204.20@tcp remote: 0xf5636d25a8e049b3 expref: 9 pid: 6312 timeout: 848 lvb_type: 0 [ 848.245242] LustreError: 5502:0:(ldlm_lockd.c:261:expired_lock_main()) Skipped 1 previous similar message [ 862.079215] LustreError: 11171:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 862.083772] LustreError: 11171:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 865.049402] Lustre: DEBUG MARKER: oleg420-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff915f42c40000.ost_server_uuid,osc.lustre-OST0000-osc-ffff915f457d0800.ost_server_uuid 40 [ 865.909861] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff915f42c40000.ost_server_uuid in IDLE state after 0 sec [ 866.674033] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff915f457d0800.ost_server_uuid in IDLE state after 0 sec [ 869.893798] Lustre: DEBUG MARKER: oleg420-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff915f42c40000.ost_server_uuid,osc.lustre-OST0001-osc-ffff915f457d0800.ost_server_uuid 40 [ 870.655610] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff915f42c40000.ost_server_uuid in IDLE state after 0 sec [ 871.536188] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff915f457d0800.ost_server_uuid in FULL state after 0 sec [ 875.115484] Lustre: DEBUG MARKER: oleg420-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff915f42c40000.ost_server_uuid,osc.lustre-OST0000-osc-ffff915f457d0800.ost_server_uuid 40 [ 875.847338] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff915f42c40000.ost_server_uuid in IDLE state after 0 sec [ 876.609237] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff915f457d0800.ost_server_uuid in IDLE state after 0 sec [ 879.377335] Lustre: DEBUG MARKER: oleg420-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff915f42c40000.ost_server_uuid,osc.lustre-OST0001-osc-ffff915f457d0800.ost_server_uuid 40 [ 880.101183] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff915f42c40000.ost_server_uuid in IDLE state after 0 sec [ 880.767586] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff915f457d0800.ost_server_uuid in FULL state after 0 sec [ 886.384599] Lustre: DEBUG MARKER: oleg420-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff915f42c40000.ost_server_uuid,osc.lustre-OST0000-osc-ffff915f457d0800.ost_server_uuid 40 [ 887.098809] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff915f42c40000.ost_server_uuid in IDLE state after 0 sec [ 887.873987] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff915f457d0800.ost_server_uuid in IDLE state after 0 sec [ 890.594850] Lustre: DEBUG MARKER: oleg420-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff915f42c40000.ost_server_uuid,osc.lustre-OST0001-osc-ffff915f457d0800.ost_server_uuid 40 [ 891.345844] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff915f42c40000.ost_server_uuid in IDLE state after 0 sec [ 892.111096] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff915f457d0800.ost_server_uuid in FULL state after 0 sec [ 892.911314] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 17:37:53 (1778535473) [ 894.248805] Lustre: DEBUG MARKER: Race attempt 0 [ 896.091572] Lustre: DEBUG MARKER: Wait for 44641 44742 for 60 sec... [ 959.187363] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 17:38:59 (1778535539) [ 1214.993678] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 17:43:15 (1778535795) [ 1241.559746] Lustre: DEBUG MARKER: == sanityn test 39a: test from 11063 ============================================================================================ 17:43:42 (1778535822) [ 1244.450224] Lustre: DEBUG MARKER: == sanityn test 39b: 11063 problem 1 ============================================================================================ 17:43:45 (1778535825) [ 1248.231723] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 17:43:48 (1778535828) [ 1252.047643] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 17:43:52 (1778535832) [ 1254.616485] Lustre: DEBUG MARKER: == sanityn test 40a: pdirops: create vs others ======================================================================== 17:43:55 (1778535835) [ 1256.498969] LustreError: 22196:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 1256.503300] LustreError: 22196:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 47 previous similar messages [ 1261.295127] LustreError: 22196:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 1261.298336] LustreError: 22196:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [ 1263.844207] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 17:44:04 (1778535844) [ 1270.399130] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 1272.708521] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 17:44:13 (1778535853) [ 1279.151072] LustreError: 5512:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 1281.847236] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 17:44:22 (1778535862) [ 1288.400107] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 1290.998365] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 17:44:31 (1778535871) [ 1297.119448] LustreError: 5512:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 1299.715978] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 17:44:40 (1778535880) [ 1305.808351] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 17:44:46 (1778535886) [ 1311.894681] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 17:44:52 (1778535892) [ 1315.079052] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 1315.082306] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 1318.208691] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 17:44:58 (1778535898) [ 1324.274324] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 17:45:04 (1778535904) [ 1325.929555] LustreError: 5512:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 1325.934287] LustreError: 5512:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 8 previous similar messages [ 1330.242146] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 17:45:10 (1778535910) [ 1336.261557] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 17:45:16 (1778535916) [ 1342.232737] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 17:45:22 (1778535922) [ 1348.632134] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 17:45:29 (1778535929) [ 1349.258214] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1349.470421] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1349.474944] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4789 [ 1350.626749] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1350.830207] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1350.834715] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4795 [ 1351.880170] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1352.083783] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1352.087113] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4796 [ 1354.513483] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1354.516804] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) Skipped 1 previous similar message [ 1354.723257] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1354.727515] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) Skipped 1 previous similar message [ 1354.730833] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4792 [ 1354.735858] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) Skipped 1 previous similar message [ 1359.771888] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1359.775466] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) Skipped 3 previous similar messages [ 1359.972738] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1359.976596] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) Skipped 3 previous similar messages [ 1359.981943] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4797 [ 1359.986201] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) Skipped 3 previous similar messages [ 1368.287418] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1368.290878] LustreError: 22195:0:(libcfs_fail.h:169:cfs_race()) Skipped 6 previous similar messages [ 1368.493943] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1368.496746] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) Skipped 6 previous similar messages [ 1368.499414] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4795 [ 1368.504941] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) Skipped 6 previous similar messages [ 1384.939108] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1384.942904] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) Skipped 12 previous similar messages [ 1385.144379] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1385.147340] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) Skipped 12 previous similar messages [ 1385.152589] LustreError: 5512:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4794 [ 1385.156845] LustreError: 5512:0:(libcfs_fail.h:178:cfs_race()) Skipped 12 previous similar messages [ 1418.219316] LustreError: 14221:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 1418.226048] LustreError: 14221:0:(libcfs_fail.h:169:cfs_race()) Skipped 24 previous similar messages [ 1418.426727] LustreError: 7801:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 1418.432562] LustreError: 7801:0:(libcfs_fail.h:180:cfs_race()) Skipped 24 previous similar messages [ 1418.437576] LustreError: 14221:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4793 [ 1418.444572] LustreError: 14221:0:(libcfs_fail.h:178:cfs_race()) Skipped 24 previous similar messages [ 1485.279191] LustreError: 5513:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 16a awake: rc=0 [ 1485.286240] LustreError: 5513:0:(libcfs_fail.h:178:cfs_race()) Skipped 46 previous similar messages [ 1485.296212] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 16a waking [ 1485.302143] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) Skipped 46 previous similar messages [ 1486.597217] LustreError: 7801:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 16a sleeping [ 1486.602757] LustreError: 7801:0:(libcfs_fail.h:169:cfs_race()) Skipped 47 previous similar messages [ 1617.887211] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 16a awake: rc=0 [ 1617.893596] LustreError: 22195:0:(libcfs_fail.h:178:cfs_race()) Skipped 19 previous similar messages [ 1617.900496] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 16a waking [ 1617.904517] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) Skipped 19 previous similar messages [ 1619.270442] LustreError: 5514:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 16a sleeping [ 1619.273591] LustreError: 5514:0:(libcfs_fail.h:169:cfs_race()) Skipped 19 previous similar messages [ 1880.031250] LustreError: 14221:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 16a awake: rc=0 [ 1880.037716] LustreError: 14221:0:(libcfs_fail.h:178:cfs_race()) Skipped 36 previous similar messages [ 1880.057860] LustreError: 22196:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 16a waking [ 1880.067507] LustreError: 22196:0:(libcfs_fail.h:180:cfs_race()) Skipped 36 previous similar messages [ 1882.330891] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 16a sleeping [ 1882.340045] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) Skipped 36 previous similar messages [ 2202.753737] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 17:59:42 (1778536782) [ 2206.624620] LustreError: 22195:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 2206.640893] LustreError: 22195:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 2208.831200] LustreError: 22195:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 2208.837380] LustreError: 22195:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 5 previous similar messages [ 2215.457717] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 17:59:55 (1778536795) [ 2221.613173] LustreError: 14236:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 2227.969909] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 18:00:07 (1778536807) [ 2231.197435] LustreError: 22195:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 2231.207237] LustreError: 22195:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 2233.296067] LustreError: 22195:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 2239.183737] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 18:00:19 (1778536819) [ 2252.856547] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 18:00:32 (1778536832) [ 2259.215114] LustreError: 22196:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 2259.220036] LustreError: 22196:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 2267.406542] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 18:00:46 (1778536846) [ 2271.583399] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 2271.593093] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 2280.661214] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 18:01:00 (1778536860) [ 2292.678105] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 18:01:12 (1778536872) [ 2297.848399] LustreError: 5512:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 2297.856235] LustreError: 5512:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 2303.501822] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 18:01:23 (1778536883) [ 2356.660394] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 18:02:16 (1778536936) [ 2360.414363] LustreError: 14221:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 2360.428397] LustreError: 14221:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 2362.647477] LustreError: 14221:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 2368.828872] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 18:02:28 (1778536948) [ 2381.347220] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 18:02:41 (1778536961) [ 2394.005902] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 18:02:53 (1778536973) [ 2405.280861] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 18:03:05 (1778536985) [ 2415.647347] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 18:03:15 (1778536995) [ 2426.775396] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 18:03:26 (1778537006) [ 2437.902894] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 18:03:38 (1778537018) [ 2439.029981] Lustre: DEBUG MARKER: SKIP: sanityn test_43i needs >= 2 MDTs [ 2440.332455] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 18:03:40 (1778537020) [ 2441.431033] LustreError: 5514:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2441.442911] LustreError: 14236:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2441.447806] LustreError: 5514:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=4987 [ 2442.404582] LustreError: 5514:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2442.410763] LustreError: 14236:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2442.416852] LustreError: 5514:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=4993 [ 2444.399896] LustreError: 14236:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2444.402910] LustreError: 14236:0:(libcfs_fail.h:169:cfs_race()) Skipped 1 previous similar message [ 2444.409555] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2444.413064] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) Skipped 1 previous similar message [ 2444.434408] LustreError: 14236:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=4976 [ 2444.441955] LustreError: 14236:0:(libcfs_fail.h:178:cfs_race()) Skipped 1 previous similar message [ 2447.521052] LustreError: 14236:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2447.524079] LustreError: 14236:0:(libcfs_fail.h:169:cfs_race()) Skipped 2 previous similar messages [ 2447.526211] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2447.538657] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) Skipped 2 previous similar messages [ 2447.545398] LustreError: 14236:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=5000 [ 2447.552254] LustreError: 14236:0:(libcfs_fail.h:178:cfs_race()) Skipped 2 previous similar messages [ 2452.032077] LustreError: 5514:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2452.033340] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2452.040049] LustreError: 5514:0:(libcfs_fail.h:169:cfs_race()) Skipped 3 previous similar messages [ 2452.065316] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) Skipped 3 previous similar messages [ 2452.070978] LustreError: 5514:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=4970 [ 2452.078616] LustreError: 5514:0:(libcfs_fail.h:178:cfs_race()) Skipped 3 previous similar messages [ 2460.246260] LustreError: 14236:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2460.247442] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2460.252699] LustreError: 14236:0:(libcfs_fail.h:169:cfs_race()) Skipped 7 previous similar messages [ 2460.266336] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) Skipped 7 previous similar messages [ 2460.271156] LustreError: 14236:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=4976 [ 2460.274347] LustreError: 14236:0:(libcfs_fail.h:178:cfs_race()) Skipped 7 previous similar messages [ 2476.514070] LustreError: 14221:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2476.518483] LustreError: 22195:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2476.521035] LustreError: 14221:0:(libcfs_fail.h:169:cfs_race()) Skipped 17 previous similar messages [ 2476.534267] LustreError: 22195:0:(libcfs_fail.h:180:cfs_race()) Skipped 17 previous similar messages [ 2476.539758] LustreError: 14221:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=4982 [ 2476.548443] LustreError: 14221:0:(libcfs_fail.h:178:cfs_race()) Skipped 17 previous similar messages [ 2508.553306] LustreError: 22196:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 167 sleeping [ 2508.553445] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 167 waking [ 2508.557835] LustreError: 22196:0:(libcfs_fail.h:169:cfs_race()) Skipped 34 previous similar messages [ 2508.573694] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) Skipped 34 previous similar messages [ 2508.584308] LustreError: 22196:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 167 awake: rc=4973 [ 2508.589564] LustreError: 22196:0:(libcfs_fail.h:178:cfs_race()) Skipped 34 previous similar messages [ 2537.501278] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 18:05:17 (1778537117) [ 2539.965093] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 2539.971180] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) Skipped 41 previous similar messages [ 2540.477758] LustreError: 5512:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4501 [ 2540.483393] LustreError: 5512:0:(libcfs_fail.h:178:cfs_race()) Skipped 42 previous similar messages [ 2573.708641] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 2573.715870] LustreError: 5514:0:(libcfs_fail.h:180:cfs_race()) Skipped 36 previous similar messages [ 2702.232717] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 2702.239390] LustreError: 14221:0:(libcfs_fail.h:180:cfs_race()) Skipped 31 previous similar messages [ 2961.245627] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 16a waking [ 2961.252768] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) Skipped 63 previous similar messages [ 3142.227845] LustreError: 22196:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 16a sleeping [ 3142.236144] LustreError: 22196:0:(libcfs_fail.h:169:cfs_race()) Skipped 150 previous similar messages [ 3142.744326] LustreError: 22196:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 16a awake: rc=4500 [ 3142.752270] LustreError: 22196:0:(libcfs_fail.h:178:cfs_race()) Skipped 150 previous similar messages [ 3322.698222] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 18:18:23 (1778537903) [ 3324.689673] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 146 sleeping for 10000ms [ 3324.695244] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [ 3326.367561] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 3326.371914] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [ 3330.296828] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 18:18:30 (1778537910) [ 3337.899803] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 18:18:38 (1778537918) [ 3346.066873] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 18:18:46 (1778537926) [ 3348.425608] LustreError: 22195:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 146 sleeping for 10000ms [ 3348.431153] LustreError: 22195:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 3350.207054] LustreError: 22195:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 3350.210427] LustreError: 22195:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 3353.736563] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 18:18:54 (1778537934) [ 3361.046245] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 18:19:01 (1778537941) [ 3368.021052] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 18:19:08 (1778537948) [ 3374.841332] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 18:19:15 (1778537955) [ 3381.693736] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 18:19:22 (1778537962) [ 3382.401436] Lustre: DEBUG MARKER: SKIP: sanityn test_44i needs >= 2 MDTs [ 3383.208510] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 18:19:23 (1778537963) [ 3441.842721] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 18:20:22 (1778538022) [ 3444.060972] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 3444.069750] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 4 previous similar messages [ 3445.640125] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 3445.649154] LustreError: 5514:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 4 previous similar messages [ 3449.150944] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 18:20:29 (1778538029) [ 3456.517554] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 18:20:36 (1778538036) [ 3464.236969] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 18:20:44 (1778538044) [ 3472.161937] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 18:20:52 (1778538052) [ 3480.005164] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 18:21:00 (1778538060) [ 3488.342967] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 18:21:08 (1778538068) [ 3495.757473] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 18:21:16 (1778538076) [ 3496.594548] Lustre: DEBUG MARKER: SKIP: sanityn test_45i needs >= 2 MDTs [ 3497.468697] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 18:21:17 (1778538077) [ 3500.252886] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 169 waking [ 3500.257109] LustreError: 5512:0:(libcfs_fail.h:180:cfs_race()) Skipped 95 previous similar messages [ 3744.053266] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 169 sleeping [ 3744.056548] LustreError: 5512:0:(libcfs_fail.h:169:cfs_race()) Skipped 131 previous similar messages [ 3744.566161] LustreError: 5512:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 169 awake: rc=4494 [ 3744.569951] LustreError: 5512:0:(libcfs_fail.h:178:cfs_race()) Skipped 131 previous similar messages [ 4075.125922] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 18:30:55 (1778538655) [ 4076.870814] LustreError: 5513:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 145 sleeping for 15000ms [ 4076.875694] LustreError: 5513:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [ 4078.440222] LustreError: 5513:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 4078.444086] LustreError: 5513:0:(fail.c:144:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [ 4081.684236] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 18:31:02 (1778538662) [ 4087.956112] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 18:31:08 (1778538668) [ 4094.172373] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 18:31:14 (1778538674) [ 4100.731679] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 18:31:21 (1778538681) [ 4107.057335] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 18:31:27 (1778538687) [ 4113.212432] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 18:31:33 (1778538693) [ 4120.038567] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 18:31:40 (1778538700) [ 4126.400446] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 18:31:47 (1778538707) [ 4126.991685] Lustre: DEBUG MARKER: SKIP: sanityn test_46i needs >= 2 MDTs [ 4127.666064] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 18:31:48 (1778538708) [ 4128.268621] Lustre: DEBUG MARKER: SKIP: sanityn test_47a needs >= 2 MDTs [ 4128.964577] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 18:31:49 (1778538709) [ 4129.627235] Lustre: DEBUG MARKER: SKIP: sanityn test_47b needs >= 2 MDTs [ 4130.343395] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 18:31:50 (1778538710) [ 4130.988241] Lustre: DEBUG MARKER: SKIP: sanityn test_47c needs >= 2 MDTs [ 4131.680994] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 18:31:52 (1778538712) [ 4132.327524] Lustre: DEBUG MARKER: SKIP: sanityn test_47d needs >= 2 MDTs [ 4133.028563] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 18:31:53 (1778538713) [ 4133.668697] Lustre: DEBUG MARKER: SKIP: sanityn test_47e needs >= 2 MDTs [ 4134.389901] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 18:31:55 (1778538715) [ 4135.023545] Lustre: DEBUG MARKER: SKIP: sanityn test_47f needs >= 2 MDTs [ 4135.774605] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 18:31:56 (1778538716) [ 4136.402979] Lustre: DEBUG MARKER: SKIP: sanityn test_47g needs >= 2 MDTs [ 4137.153907] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 18:31:57 (1778538717) [ 4145.009354] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 18:32:05 (1778538725) [ 4149.857239] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 18:32:10 (1778538730) [ 4164.899320] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 18:32:25 (1778538745) [ 4167.455169] LustreError: 22195:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 172 awake [ 4167.458513] LustreError: 22195:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 37 previous similar messages [ 4172.328848] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 18:32:32 (1778538752) [ 4176.188559] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 18:32:36 (1778538756) [ 4181.074429] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 18:32:41 (1778538761) [ 4186.719183] LustreError: 14236:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 153 awake [ 4186.724791] LustreError: 14236:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 4203.656487] LustreError: 5514:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 154 awake [ 4203.660194] LustreError: 5514:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 4206.387295] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 18:33:07 (1778538787) [ 4206.796413] LustreError: 7801:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 156 sleeping for 5000ms [ 4206.800037] LustreError: 7801:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 13 previous similar messages [ 4214.357121] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 18:33:15 (1778538795) [ 4222.510607] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 18:33:23 (1778538803) [ 4236.441924] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 18:33:37 (1778538817) [ 4241.983560] LustreError: 5512:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 155 awake [ 4241.990419] LustreError: 5512:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 4 previous similar messages [ 4246.777140] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 18:33:47 (1778538827) [ 4249.734196] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 4252.437278] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 18:33:53 (1778538833) [ 4255.302132] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 18:33:55 (1778538835) [ 4256.002313] Lustre: DEBUG MARKER: SKIP: sanityn test_71a ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 4256.664814] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 18:33:57 (1778538837) [ 4257.378713] Lustre: DEBUG MARKER: SKIP: sanityn test_71b ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 4258.045313] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 18:33:58 (1778538838) [ 4258.689865] Lustre: DEBUG MARKER: SKIP: sanityn test_71c support only ldiskfs ost [ 4259.379479] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 18:34:00 (1778538840) [ 4260.099224] Lustre: DEBUG MARKER: SKIP: sanityn test_71d ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 4260.841143] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 18:34:01 (1778538841) [ 4263.730619] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 18:34:04 (1778538844) [ 4266.580224] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 18:34:07 (1778538847) [ 4273.401867] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 18:34:14 (1778538854) [ 4281.489644] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 18:34:22 (1778538862) [ 4306.298419] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 18:34:46 (1778538886) [ 4309.837819] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 18:34:50 (1778538890) [ 4312.140349] BUG: sleeping function called from invalid context at kernel/workqueue.c:3092 [ 4312.143560] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 162759, name: lctl [ 4312.146501] CPU: 0 PID: 162759 Comm: lctl Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [ 4312.150835] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4312.154078] Call Trace: [ 4312.155126] ? dump_stack+0xbb/0x10e [ 4312.156410] ? ___might_sleep.cold.92+0xd9/0x107 [ 4312.158157] ? __might_sleep+0x59/0xc0 [ 4312.159739] ? flush_work+0x5a/0x390 [ 4312.160984] ? ptlrpc_lprocfs_svc_req_history_start+0x410/0x410 [ptlrpc] [ 4312.163926] ? single_open+0x70/0xd0 [ 4312.165419] ? refcount_dec_and_test+0x15/0x20 [ 4312.167236] ? debugfs_file_put+0x1e/0x50 [ 4312.168612] ? ima_file_check+0x71/0xa0 [ 4312.169481] ? work_busy+0x120/0x120 [ 4312.170786] ? __cancel_work_timer+0x1cc/0x2e0 [ 4312.172696] ? do_raw_spin_unlock+0x75/0x190 [ 4312.174667] ? _raw_spin_unlock+0x12/0x30 [ 4312.176251] ? nrs_crrn_stop+0x290/0x290 [ptlrpc] [ 4312.178424] ? cancel_work_sync+0x14/0x20 [ 4312.180039] ? rhashtable_free_and_destroy+0x28/0x1e0 [ 4312.181873] ? nrs_crrn_stop+0x63/0x290 [ptlrpc] [ 4312.183191] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4312.184637] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4312.186583] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4312.188850] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4312.191252] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4312.193536] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4312.196136] ? full_proxy_write+0x5e/0xa0 [ 4312.197632] ? __vfs_write+0x1c/0x60 [ 4312.198545] ? vfs_write+0xd8/0x2b0 [ 4312.199508] ? ksys_write+0x66/0x120 [ 4312.200741] ? __x64_sys_write+0x1e/0x30 [ 4312.201913] ? do_syscall_64+0xc1/0x440 [ 4312.202810] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4314.662709] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 18:34:55 (1778538895) [ 4318.526105] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4318.530904] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 163151, name: lctl [ 4318.533409] CPU: 2 PID: 163151 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4318.536684] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4318.539726] Call Trace: [ 4318.540602] ? dump_stack+0xbb/0x10e [ 4318.541926] ? ___might_sleep.cold.92+0xd9/0x107 [ 4318.543604] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4318.545248] ? nrs_orr_stop+0x7d/0x330 [ptlrpc] [ 4318.547444] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4318.549176] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4318.551541] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4318.553784] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4318.555876] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4318.557941] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4318.560269] ? full_proxy_write+0x5e/0xa0 [ 4318.561933] ? __vfs_write+0x1c/0x60 [ 4318.563102] ? vfs_write+0xd8/0x2b0 [ 4318.564456] ? ksys_write+0x66/0x120 [ 4318.565883] ? __x64_sys_write+0x1e/0x30 [ 4318.567060] ? do_syscall_64+0xc1/0x440 [ 4318.568958] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4321.582631] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 18:35:02 (1778538902) [ 4325.572147] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4325.577882] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 163545, name: lctl [ 4325.582447] CPU: 1 PID: 163545 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4325.586481] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4325.590478] Call Trace: [ 4325.591619] ? dump_stack+0xbb/0x10e [ 4325.593150] ? ___might_sleep.cold.92+0xd9/0x107 [ 4325.595004] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4325.596883] ? nrs_orr_stop+0x7d/0x330 [ptlrpc] [ 4325.598915] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4325.601016] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4325.603676] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4325.605874] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4325.608181] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4325.610710] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4325.613690] ? full_proxy_write+0x5e/0xa0 [ 4325.615164] ? __vfs_write+0x1c/0x60 [ 4325.616379] ? vfs_write+0xd8/0x2b0 [ 4325.617678] ? ksys_write+0x66/0x120 [ 4325.619333] ? __x64_sys_write+0x1e/0x30 [ 4325.621034] ? do_syscall_64+0xc1/0x440 [ 4325.622673] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4328.321787] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 18:35:08 (1778538908) [ 4335.329424] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4335.333209] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 164276, name: lctl [ 4335.335584] CPU: 0 PID: 164276 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4335.338965] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4335.341636] Call Trace: [ 4335.342605] ? dump_stack+0xbb/0x10e [ 4335.343762] ? ___might_sleep.cold.92+0xd9/0x107 [ 4335.345038] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4335.346290] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4335.347666] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4335.349286] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4335.351563] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4335.353635] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4335.355351] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4335.357192] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4335.359438] ? full_proxy_write+0x5e/0xa0 [ 4335.360609] ? __vfs_write+0x1c/0x60 [ 4335.361737] ? vfs_write+0xd8/0x2b0 [ 4335.362903] ? ksys_write+0x66/0x120 [ 4335.363825] ? __x64_sys_write+0x1e/0x30 [ 4335.365132] ? do_syscall_64+0xc1/0x440 [ 4335.366364] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4338.405899] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 18:35:19 (1778538919) [ 4344.736565] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4344.740407] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 165007, name: lctl [ 4344.743911] CPU: 0 PID: 165007 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4344.747819] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4344.750540] Call Trace: [ 4344.751151] ? dump_stack+0xbb/0x10e [ 4344.752262] ? ___might_sleep.cold.92+0xd9/0x107 [ 4344.754078] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4344.756539] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4344.758905] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4344.761325] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4344.763870] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4344.766115] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4344.768023] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4344.770361] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4344.773310] ? full_proxy_write+0x5e/0xa0 [ 4344.774801] ? __vfs_write+0x1c/0x60 [ 4344.776037] ? vfs_write+0xd8/0x2b0 [ 4344.777263] ? ksys_write+0x66/0x120 [ 4344.778808] ? __x64_sys_write+0x1e/0x30 [ 4344.780362] ? do_syscall_64+0xc1/0x440 [ 4344.781937] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4348.265689] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 18:35:28 (1778538928) [ 4349.382159] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4349.388149] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 165306, name: lctl [ 4349.391618] CPU: 3 PID: 165306 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4349.395246] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4349.397239] Call Trace: [ 4349.398005] ? dump_stack+0xbb/0x10e [ 4349.399162] ? ___might_sleep.cold.92+0xd9/0x107 [ 4349.402103] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4349.403910] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4349.405204] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4349.406750] ? nrs_policy_stop_locked+0x2a1/0x2f0 [ptlrpc] [ 4349.410212] ? nrs_policy_start_locked+0x792/0x8f0 [ptlrpc] [ 4349.413398] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4349.415467] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4349.421891] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4349.428341] ? full_proxy_write+0x5e/0xa0 [ 4349.432054] ? __vfs_write+0x1c/0x60 [ 4349.434325] ? vfs_write+0xd8/0x2b0 [ 4349.436440] ? ksys_write+0x66/0x120 [ 4349.439963] ? __x64_sys_write+0x1e/0x30 [ 4349.444413] ? do_syscall_64+0xc1/0x440 [ 4349.447387] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4353.376637] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 18:35:33 (1778538933) [ 4358.468387] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 18:35:39 (1778538939) [ 4365.358188] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4365.362045] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 166957, name: lctl [ 4365.364487] CPU: 1 PID: 166957 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4365.367911] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4365.371200] Call Trace: [ 4365.372071] ? dump_stack+0xbb/0x10e [ 4365.373190] ? ___might_sleep.cold.92+0xd9/0x107 [ 4365.374915] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4365.376423] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4365.378137] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4365.379894] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4365.382222] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4365.384635] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4365.386616] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4365.388838] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4365.391804] ? full_proxy_write+0x5e/0xa0 [ 4365.393459] ? __vfs_write+0x1c/0x60 [ 4365.394931] ? vfs_write+0xd8/0x2b0 [ 4365.396105] ? ksys_write+0x66/0x120 [ 4365.397550] ? __x64_sys_write+0x1e/0x30 [ 4365.399015] ? do_syscall_64+0xc1/0x440 [ 4365.400527] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4367.968667] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 18:35:48 (1778538948) [ 4415.399618] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4415.404664] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 167749, name: lctl [ 4415.407294] CPU: 1 PID: 167749 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4415.410215] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4415.413610] Call Trace: [ 4415.414293] ? dump_stack+0xbb/0x10e [ 4415.415235] ? ___might_sleep.cold.92+0xd9/0x107 [ 4415.417026] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4415.419749] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4415.422083] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4415.424040] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4415.426848] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4415.429401] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4415.431548] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4415.433927] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4415.437097] ? full_proxy_write+0x5e/0xa0 [ 4415.438863] ? __vfs_write+0x1c/0x60 [ 4415.440399] ? vfs_write+0xd8/0x2b0 [ 4415.441578] ? ksys_write+0x66/0x120 [ 4415.443791] ? __x64_sys_write+0x1e/0x30 [ 4415.445724] ? do_syscall_64+0xc1/0x440 [ 4415.447899] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4420.907286] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 18:36:41 (1778539001) [ 4484.062534] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4484.066115] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 168548, name: lctl [ 4484.067800] CPU: 2 PID: 168548 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4484.070851] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4484.073668] Call Trace: [ 4484.074495] ? dump_stack+0xbb/0x10e [ 4484.076012] ? ___might_sleep.cold.92+0xd9/0x107 [ 4484.077833] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4484.079159] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4484.081408] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4484.083642] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4484.085667] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4484.087279] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4484.088724] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4484.090910] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4484.092891] ? full_proxy_write+0x5e/0xa0 [ 4484.094149] ? __vfs_write+0x1c/0x60 [ 4484.095572] ? vfs_write+0xd8/0x2b0 [ 4484.096475] ? ksys_write+0x66/0x120 [ 4484.097381] ? __x64_sys_write+0x1e/0x30 [ 4484.098326] ? do_syscall_64+0xc1/0x440 [ 4484.099238] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4550.632865] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4550.636744] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 169160, name: lctl [ 4550.639342] CPU: 1 PID: 169160 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4550.644185] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4550.647176] Call Trace: [ 4550.647895] ? dump_stack+0xbb/0x10e [ 4550.648871] ? ___might_sleep.cold.92+0xd9/0x107 [ 4550.650072] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4550.651649] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4550.653266] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4550.655000] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4550.657000] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4550.658931] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4550.660999] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4550.663060] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4550.665547] ? full_proxy_write+0x5e/0xa0 [ 4550.666846] ? __vfs_write+0x1c/0x60 [ 4550.668067] ? vfs_write+0xd8/0x2b0 [ 4550.669296] ? ksys_write+0x66/0x120 [ 4550.670604] ? __x64_sys_write+0x1e/0x30 [ 4550.672092] ? do_syscall_64+0xc1/0x440 [ 4550.673448] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4556.268077] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with NID/JobID/OPCode expression ========================================================== 18:38:56 (1778539136) [ 4923.841136] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4923.845107] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 174529, name: lctl [ 4923.848192] CPU: 1 PID: 174529 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4923.855397] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4923.859977] Call Trace: [ 4923.861543] ? dump_stack+0xbb/0x10e [ 4923.863046] ? ___might_sleep.cold.92+0xd9/0x107 [ 4923.865156] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4923.867484] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4923.869306] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4923.871300] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4923.874873] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4923.877741] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4923.879686] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4923.882765] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4923.886365] ? full_proxy_write+0x5e/0xa0 [ 4923.888160] ? __vfs_write+0x1c/0x60 [ 4923.889945] ? vfs_write+0xd8/0x2b0 [ 4923.891436] ? ksys_write+0x66/0x120 [ 4923.893161] ? __x64_sys_write+0x1e/0x30 [ 4923.894892] ? do_syscall_64+0xc1/0x440 [ 4923.896410] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4929.768472] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 18:45:10 (1778539510) [ 4930.724620] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4930.728663] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 174823, name: lctl [ 4930.732264] CPU: 2 PID: 174823 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4930.737843] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4930.742268] Call Trace: [ 4930.743459] ? dump_stack+0xbb/0x10e [ 4930.745333] ? ___might_sleep.cold.92+0xd9/0x107 [ 4930.747581] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4930.752807] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4930.754740] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4930.757538] ? nrs_policy_stop_locked+0x2a1/0x2f0 [ptlrpc] [ 4930.761662] ? nrs_policy_start_locked+0x792/0x8f0 [ptlrpc] [ 4930.766934] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4930.771389] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4930.778125] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4930.781419] ? full_proxy_write+0x5e/0xa0 [ 4930.783831] ? __vfs_write+0x1c/0x60 [ 4930.785924] ? vfs_write+0xd8/0x2b0 [ 4930.788202] ? ksys_write+0x66/0x120 [ 4930.790593] ? __x64_sys_write+0x1e/0x30 [ 4930.792654] ? do_syscall_64+0xc1/0x440 [ 4930.794690] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4931.736451] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 4931.743905] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 174920, name: lctl [ 4931.748396] CPU: 3 PID: 174920 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 4931.753132] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 4931.756727] Call Trace: [ 4931.759162] ? dump_stack+0xbb/0x10e [ 4931.761131] ? ___might_sleep.cold.92+0xd9/0x107 [ 4931.763308] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 4931.765904] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 4931.768227] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 4931.770697] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 4931.773805] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 4931.777183] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 4931.779460] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 4931.781733] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 4931.784763] ? full_proxy_write+0x5e/0xa0 [ 4931.786582] ? __vfs_write+0x1c/0x60 [ 4931.788893] ? vfs_write+0xd8/0x2b0 [ 4931.790351] ? ksys_write+0x66/0x120 [ 4931.791426] ? __x64_sys_write+0x1e/0x30 [ 4931.792772] ? do_syscall_64+0xc1/0x440 [ 4931.794941] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 4934.708508] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 18:45:15 (1778539515) [ 4986.512211] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 18:46:07 (1778539567) [ 5051.105765] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 5051.111096] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 176650, name: lctl [ 5051.113393] CPU: 2 PID: 176650 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 5051.117124] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 5051.119211] Call Trace: [ 5051.119954] ? dump_stack+0xbb/0x10e [ 5051.120869] ? ___might_sleep.cold.92+0xd9/0x107 [ 5051.122369] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 5051.123884] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 5051.125654] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 5051.127466] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 5051.129561] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 5051.131462] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 5051.133430] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 5051.135584] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 5051.137926] ? full_proxy_write+0x5e/0xa0 [ 5051.139380] ? __vfs_write+0x1c/0x60 [ 5051.140329] ? vfs_write+0xd8/0x2b0 [ 5051.141640] ? ksys_write+0x66/0x120 [ 5051.142406] ? __x64_sys_write+0x1e/0x30 [ 5051.143288] ? do_syscall_64+0xc1/0x440 [ 5051.144545] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 5056.487483] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 18:47:17 (1778539637) [ 5058.608960] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 5058.612983] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 177137, name: lctl [ 5058.615746] CPU: 2 PID: 177137 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 5058.619329] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 5058.622093] Call Trace: [ 5058.622895] ? dump_stack+0xbb/0x10e [ 5058.624040] ? ___might_sleep.cold.92+0xd9/0x107 [ 5058.625998] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 5058.628070] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 5058.629974] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 5058.632056] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 5058.634093] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 5058.635514] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 5058.637010] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 5058.638588] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 5058.640761] ? full_proxy_write+0x5e/0xa0 [ 5058.641877] ? __vfs_write+0x1c/0x60 [ 5058.643124] ? vfs_write+0xd8/0x2b0 [ 5058.644256] ? ksys_write+0x66/0x120 [ 5058.645250] ? __x64_sys_write+0x1e/0x30 [ 5058.646555] ? do_syscall_64+0xc1/0x440 [ 5058.647747] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 5060.981800] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 18:47:21 (1778539641) [ 5102.867146] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 5102.872460] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 187186, name: lctl [ 5102.875559] CPU: 2 PID: 187186 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 5102.879426] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 5102.883452] Call Trace: [ 5102.884256] ? dump_stack+0xbb/0x10e [ 5102.885164] ? ___might_sleep.cold.92+0xd9/0x107 [ 5102.887149] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 5102.888610] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 5102.889827] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 5102.891672] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 5102.893796] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 5102.895449] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 5102.897036] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 5102.899019] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 5102.901097] ? full_proxy_write+0x5e/0xa0 [ 5102.902183] ? __vfs_write+0x1c/0x60 [ 5102.903239] ? vfs_write+0xd8/0x2b0 [ 5102.904307] ? ksys_write+0x66/0x120 [ 5102.905473] ? __x64_sys_write+0x1e/0x30 [ 5102.906520] ? do_syscall_64+0xc1/0x440 [ 5102.907581] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 5103.451680] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 18:48:04 (1778539684) [ 5115.953758] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 5115.956680] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 188965, name: lctl [ 5115.958334] CPU: 3 PID: 188965 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 5115.961023] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 5115.963171] Call Trace: [ 5115.963959] ? dump_stack+0xbb/0x10e [ 5115.964752] ? ___might_sleep.cold.92+0xd9/0x107 [ 5115.965729] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 5115.967322] ? nrs_tbf_stop+0x66/0x390 [ptlrpc] [ 5115.969063] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 5115.970416] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 5115.972152] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 5115.973960] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 5115.975450] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 5115.977114] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 5115.978931] ? full_proxy_write+0x5e/0xa0 [ 5115.979833] ? __vfs_write+0x1c/0x60 [ 5115.980592] ? vfs_write+0xd8/0x2b0 [ 5115.981400] ? ksys_write+0x66/0x120 [ 5115.982393] ? __x64_sys_write+0x1e/0x30 [ 5115.983346] ? do_syscall_64+0xc1/0x440 [ 5115.984398] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 5116.503567] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 18:48:17 (1778539697) [ 5117.493184] BUG: sleeping function called from invalid context at /home/green/git/lustre-release/libcfs/libcfs/hash.c:1155 [ 5117.497492] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 189147, name: lctl [ 5117.499775] CPU: 2 PID: 189147 Comm: lctl Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 5117.502856] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 5117.504712] Call Trace: [ 5117.505470] ? dump_stack+0xbb/0x10e [ 5117.506311] ? ___might_sleep.cold.92+0xd9/0x107 [ 5117.507460] ? cfs_hash_putref+0x337/0x660 [libcfs] [ 5117.508647] ? nrs_orr_stop+0x7d/0x330 [ptlrpc] [ 5117.510343] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 5117.511692] ? nrs_policy_stop_primary.isra.5+0x1de/0x240 [ptlrpc] [ 5117.513030] ? nrs_policy_start_locked+0x6f3/0x8f0 [ptlrpc] [ 5117.514471] ? nrs_policy_ctl+0x25c/0x3e0 [ptlrpc] [ 5117.515674] ? ptlrpc_nrs_policy_control+0x105/0x450 [ptlrpc] [ 5117.516993] ? ptlrpc_lprocfs_nrs_policies_seq_write+0x59e/0x7d0 [ptlrpc] [ 5117.518689] ? full_proxy_write+0x5e/0xa0 [ 5117.519508] ? __vfs_write+0x1c/0x60 [ 5117.520552] ? vfs_write+0xd8/0x2b0 [ 5117.521241] ? ksys_write+0x66/0x120 [ 5117.522101] ? __x64_sys_write+0x1e/0x30 [ 5117.522968] ? do_syscall_64+0xc1/0x440 [ 5117.524154] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 5120.061201] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 18:48:20 (1778539700) [ 5120.616634] LustreError: 14221:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 160 sleeping for 10000ms [ 5120.620318] LustreError: 14221:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 5 previous similar messages [ 5130.711848] LustreError: 14221:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 160 awake [ 5130.716606] LustreError: 14221:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 5130.722092] Lustre: *** cfs_fail_loc=131, val=0*** [ 5133.072116] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 18:48:33 (1778539713) [ 5133.610690] Lustre: DEBUG MARKER: SKIP: sanityn test_80a needs >= 2 MDTs [ 5134.245091] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 18:48:34 (1778539714) [ 5134.801194] Lustre: DEBUG MARKER: SKIP: sanityn test_80b needs >= 2 MDTs [ 5135.390257] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 18:48:36 (1778539716) [ 5135.913800] Lustre: DEBUG MARKER: SKIP: sanityn test_81a needs >= 2 MDTs [ 5136.478471] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 18:48:37 (1778539717) [ 5137.005589] Lustre: DEBUG MARKER: SKIP: sanityn test_81b We need at least 2 MDTs for this test [ 5137.520889] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 18:48:38 (1778539718) [ 5137.999037] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 5138.517897] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 18:48:39 (1778539719) [ 5140.689687] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 18:48:41 (1778539721) [ 5141.221779] Lustre: DEBUG MARKER: SKIP: sanityn test_83 needs >= 2 MDTs [ 5141.850319] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 18:48:42 (1778539722) [ 5142.403837] LustreError: 22196:0:(libcfs_fail.h:202:cfs_race_wait()) cfs_race id 60b sleeping [ 5147.238848] LustreError: 5514:0:(libcfs_fail.h:218:cfs_race_wakeup()) cfs_fail_race id 60b waking [ 5147.241870] LustreError: 22196:0:(libcfs_fail.h:205:cfs_race_wait()) cfs_fail_race id 60b awake: rc=0 [ 5149.447884] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 18:48:50 (1778539730) [ 5150.006524] Lustre: DEBUG MARKER: SKIP: sanityn test_90 needs >= 2 MDTs [ 5150.631383] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 18:48:51 (1778539731) [ 5151.188167] Lustre: DEBUG MARKER: SKIP: sanityn test_91 needs >= 2 MDTs [ 5151.803077] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 18:48:52 (1778539732) [ 5152.317269] Lustre: DEBUG MARKER: SKIP: sanityn test_92 needs >= 2 MDTs [ 5152.879046] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 18:48:53 (1778539733) [ 5153.853176] LustreError: 22196:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 163 sleeping for 2000ms [ 5155.935103] LustreError: 22196:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 163 awake [ 5162.101290] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 18:49:02 (1778539742) [ 5172.567334] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 18:49:13 (1778539753) [ 5181.117938] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 18:49:21 (1778539761) [ 5181.657519] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [ 5182.289800] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 18:49:22 (1778539762) [ 5184.845991] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 18:49:25 (1778539765) [ 5187.323935] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 18:49:28 (1778539768) [ 5189.881166] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 18:49:30 (1778539770) [ 5192.374986] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 18:49:33 (1778539773) [ 5194.909381] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 18:49:35 (1778539775) [ 5197.393892] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 18:49:38 (1778539778) [ 5200.745199] Lustre: DEBUG MARKER: SKIP: sanityn test_102 skipping ALWAYS excluded test 102 [ 5201.419908] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 18:49:42 (1778539782) [ 5204.087170] LustreError: 16285:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 415 awake [ 5204.090103] LustreError: 16285:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 5209.086210] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 18:49:49 (1778539789) [ 5209.735229] Lustre: DEBUG MARKER: SKIP: sanityn test_104 ldiskfs only test [ 5210.441677] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 18:49:51 (1778539791) [ 5258.707803] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 18:50:39 (1778539839) [ 5259.240598] Lustre: DEBUG MARKER: SKIP: sanityn test_106a Test only for ldiskfs and statx() supported [ 5259.818968] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 18:50:40 (1778539840) [ 5262.185938] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 18:50:42 (1778539842) [ 5264.516057] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 18:50:45 (1778539845) [ 5269.077959] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 18:50:49 (1778539849) [ 5277.578757] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 18:50:58 (1778539858) [ 5284.341166] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 18:51:05 (1778539865) [ 5286.206956] Lustre: DEBUG MARKER: Iteration 1 [ 5295.849552] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5297.715600] Lustre: DEBUG MARKER: Iteration 2 [ 5307.620246] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5309.311745] Lustre: DEBUG MARKER: Iteration 3 [ 5319.134851] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5320.808703] Lustre: DEBUG MARKER: Iteration 4 [ 5330.287335] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5331.748209] Lustre: DEBUG MARKER: Iteration 5 [ 5341.504793] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5343.050417] Lustre: DEBUG MARKER: Iteration 6 [ 5352.773063] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5354.362398] Lustre: DEBUG MARKER: Iteration 7 [ 5364.001938] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5365.768479] Lustre: DEBUG MARKER: Iteration 8 [ 5375.384435] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5376.907873] Lustre: DEBUG MARKER: Iteration 9 [ 5386.804487] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5388.264472] Lustre: DEBUG MARKER: Iteration 10 [ 5397.985395] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5399.623801] Lustre: DEBUG MARKER: Iteration 11 [ 5408.822802] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5410.219968] Lustre: DEBUG MARKER: Iteration 12 [ 5419.297700] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5420.697922] Lustre: DEBUG MARKER: Iteration 13 [ 5429.698326] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5431.173919] Lustre: DEBUG MARKER: Iteration 14 [ 5440.296329] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5441.933955] Lustre: DEBUG MARKER: Iteration 15 [ 5451.065917] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5452.650989] Lustre: DEBUG MARKER: Iteration 16 [ 5461.849079] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5463.426130] Lustre: DEBUG MARKER: Iteration 17 [ 5472.851197] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5474.368830] Lustre: DEBUG MARKER: Iteration 18 [ 5483.626586] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5485.289253] Lustre: DEBUG MARKER: Iteration 19 [ 5494.321043] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5495.813382] Lustre: DEBUG MARKER: Iteration 20 [ 5504.985305] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5506.366232] Lustre: DEBUG MARKER: Iteration 21 [ 5515.632177] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5517.088272] Lustre: DEBUG MARKER: Iteration 22 [ 5526.172543] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5527.466667] Lustre: DEBUG MARKER: Iteration 23 [ 5536.169883] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5537.507259] Lustre: DEBUG MARKER: Iteration 24 [ 5546.636514] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5548.004712] Lustre: DEBUG MARKER: Iteration 25 [ 5556.501268] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5557.728835] Lustre: DEBUG MARKER: Iteration 26 [ 5566.343234] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5567.636812] Lustre: DEBUG MARKER: Iteration 27 [ 5576.453383] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5577.794844] Lustre: DEBUG MARKER: Iteration 28 [ 5586.575306] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5587.939724] Lustre: DEBUG MARKER: Iteration 29 [ 5596.713423] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5598.131060] Lustre: DEBUG MARKER: Iteration 30 [ 5607.017375] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5608.450281] Lustre: DEBUG MARKER: Iteration 31 [ 5617.434162] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5618.830792] Lustre: DEBUG MARKER: Iteration 32 [ 5627.776053] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5629.144194] Lustre: DEBUG MARKER: Iteration 33 [ 5643.058417] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5645.717894] Lustre: DEBUG MARKER: Iteration 34 [ 5660.107930] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5663.259200] Lustre: DEBUG MARKER: Iteration 35 [ 5677.478189] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5680.249245] Lustre: DEBUG MARKER: Iteration 36 [ 5692.317608] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5694.461185] Lustre: DEBUG MARKER: Iteration 37 [ 5705.219358] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5707.049718] Lustre: DEBUG MARKER: Iteration 38 [ 5717.754716] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5719.678908] Lustre: DEBUG MARKER: Iteration 39 [ 5730.907484] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5733.128211] Lustre: DEBUG MARKER: Iteration 40 [ 5744.138964] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5746.016166] Lustre: DEBUG MARKER: Iteration 41 [ 5756.552116] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5758.356863] Lustre: DEBUG MARKER: Iteration 42 [ 5769.227494] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5771.303254] Lustre: DEBUG MARKER: Iteration 43 [ 5783.744604] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5786.224638] Lustre: DEBUG MARKER: Iteration 44 [ 5798.288564] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5800.512586] Lustre: DEBUG MARKER: Iteration 45 [ 5810.969504] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5812.978824] Lustre: DEBUG MARKER: Iteration 46 [ 5823.570368] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5825.465446] Lustre: DEBUG MARKER: Iteration 47 [ 5836.462089] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5838.403845] Lustre: DEBUG MARKER: Iteration 48 [ 5849.476249] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5851.532312] Lustre: DEBUG MARKER: Iteration 49 [ 5862.712758] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5864.929658] Lustre: DEBUG MARKER: Iteration 50 [ 5877.129227] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing load_modules_local [ 5883.646883] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 19:01:04 (1778540464) [ 5885.681477] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 534 sleeping for 9000ms [ 5885.685378] LustreError: 5514:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 5 previous similar messages [ 5891.551460] Lustre: lustre-MDT0000: Client 13d38c83-da8b-4a1a-a782-2c9689e5954a (at 192.168.204.20@tcp) reconnecting [ 5894.743112] LustreError: 5514:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 534 awake [ 5894.748102] LustreError: 5514:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 5894.754706] Lustre: 5514:0:(service.c:2348:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (6/3s); client may timeout req@000000004b7fc844 x1864934833001344/t0(0) o101->13d38c83-da8b-4a1a-a782-2c9689e5954a@192.168.204.20@tcp:562/0 lens 576/696 e 0 to 0 dl 1778540472 ref 1 fl Complete:/0/0 rc 0/0 job:'stat.0' [ 5898.740501] Lustre: lustre-MDT0000: Client 13d38c83-da8b-4a1a-a782-2c9689e5954a (at 192.168.204.20@tcp) reconnecting [ 5905.898165] Lustre: lustre-MDT0000: Client 13d38c83-da8b-4a1a-a782-2c9689e5954a (at 192.168.204.20@tcp) reconnecting [ 5913.056621] Lustre: lustre-MDT0000: Client 13d38c83-da8b-4a1a-a782-2c9689e5954a (at 192.168.204.20@tcp) reconnecting [ 5920.224082] Lustre: lustre-MDT0000: Client 13d38c83-da8b-4a1a-a782-2c9689e5954a (at 192.168.204.20@tcp) reconnecting [ 5921.497925] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 19:01:42 (1778540502) [ 5922.255444] Lustre: DEBUG MARKER: SKIP: sanityn test_111 needs >= 2 MDTs [ 5923.057454] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 19:01:43 (1778540503) [ 5923.763271] Lustre: DEBUG MARKER: SKIP: sanityn test_112 We need at least 2 MDTs for this test [ 5924.591926] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 19:01:45 (1778540505) [ 5927.961582] Lustre: DEBUG MARKER: cleanup: ====================================================== [ 5928.932942] Lustre: DEBUG MARKER: == sanityn test complete, duration 5720 sec ============== 19:01:49 (1778540509) [ 6074.526901] Lustre: server umount lustre-MDT0000 complete [ 6076.717680] LustreError: 18301:0:(ldlm_lockd.c:2526:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1778540657 with bad export cookie 9336886466713098831 [ 6076.724334] LustreError: 166-1: MGC192.168.204.120@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6083.039353] Lustre: 221869:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1778540657/real 1778540657] req@0000000007763ac3 x1864928795486208/t0(0) o39->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1778540663 ref 2 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'umount.0' [ 6083.100182] Lustre: server umount lustre-OST0000 complete [ 6090.207272] Lustre: 222077:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1778540665/real 1778540665] req@0000000007763ac3 x1864928795486656/t0(0) o39->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1778540671 ref 2 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'umount.0' [ 6090.279448] BUG: sleeping function called from invalid context at kernel/workqueue.c:3092 [ 6090.283209] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 222077, name: umount [ 6090.288124] CPU: 1 PID: 222077 Comm: umount Kdump: loaded Tainted: G W O -------- - - 4.18.0rh8.10-debug #2 [ 6090.293621] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 6090.297753] Call Trace: [ 6090.298819] ? dump_stack+0xbb/0x10e [ 6090.300855] ? ___might_sleep.cold.92+0xd9/0x107 [ 6090.302883] ? __might_sleep+0x59/0xc0 [ 6090.304424] ? flush_work+0x5a/0x390 [ 6090.305800] ? vsnprintf+0x201/0x7f0 [ 6090.307249] ? do_raw_spin_unlock+0x75/0x190 [ 6090.308757] ? _raw_spin_unlock+0x12/0x30 [ 6090.310602] ? cfs_trace_unlock_tcd+0x28/0xa0 [libcfs] [ 6090.312445] ? libcfs_debug_msg+0xd1b/0xf70 [libcfs] [ 6090.314870] ? work_busy+0x120/0x120 [ 6090.316497] ? __cancel_work_timer+0x1cc/0x2e0 [ 6090.317987] ? debug_check_no_obj_freed+0x16f/0x2e8 [ 6090.319424] ? nrs_crrn_stop+0x290/0x290 [ptlrpc] [ 6090.322535] ? cancel_work_sync+0x14/0x20 [ 6090.323858] ? rhashtable_free_and_destroy+0x28/0x1e0 [ 6090.328890] ? nrs_crrn_stop+0x63/0x290 [ptlrpc] [ 6090.330997] ? nrs_policy_stop0+0x49/0x260 [ptlrpc] [ 6090.334905] ? nrs_policy_stop_locked+0x2a1/0x2f0 [ptlrpc] [ 6090.337007] ? nrs_policy_unregister+0x9a/0x5c0 [ptlrpc] [ 6090.338930] ? ptlrpc_service_nrs_cleanup+0x115/0x560 [ptlrpc] [ 6090.340808] ? ptlrpc_unregister_service+0x666/0x770 [ptlrpc] [ 6090.342981] ? ost_cleanup+0x6d/0x250 [ost] [ 6090.344177] ? class_free_dev+0x3de/0x780 [obdclass] [ 6090.346388] ? class_export_put+0x33a/0x3d0 [obdclass] [ 6090.347817] ? class_unlink_export+0x249/0x2a0 [obdclass] [ 6090.350080] ? class_decref+0x9d/0x1b0 [obdclass] [ 6090.351747] ? class_detach+0x2d0/0x370 [obdclass] [ 6090.353385] ? class_process_config+0x1fcf/0x2b90 [obdclass] [ 6090.355692] ? class_manual_cleanup+0x5b6/0xa20 [obdclass] [ 6090.358250] ? server_put_super+0xf80/0x1940 [obdclass] [ 6090.360568] ? _raw_spin_unlock+0x12/0x30 [ 6090.363471] ? evict_inodes+0x1d4/0x260 [ 6090.365828] ? generic_shutdown_super+0xb1/0x1b0 [ 6090.368223] ? kill_anon_super+0x1c/0x40 [ 6090.370178] ? lustre_kill_super+0x2a/0x60 [lustre] [ 6090.372505] ? deactivate_locked_super+0x52/0xd0 [ 6090.374525] ? deactivate_super+0x83/0x90 [ 6090.376396] ? cleanup_mnt+0x5f/0xe0 [ 6090.377853] ? __cleanup_mnt+0x16/0x20 [ 6090.380843] ? task_work_run+0xc6/0x110 [ 6090.382224] ? exit_to_usermode_loop+0x1dd/0x1f0 [ 6090.384543] ? do_syscall_64+0x3d6/0x440 [ 6090.386260] ? entry_SYSCALL_64_after_hwframe+0x49/0xae [ 6090.449436] Lustre: server umount lustre-OST0001 complete [ 6096.564206] Lustre: DEBUG MARKER: oleg420-server.virtnet: executing unload_modules_local [ 6097.860118] Key type lgssc unregistered [ 6097.982151] LNet: 222678:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6097.987091] LNet: Removed LNI 192.168.204.120@tcp [ 6098.299702] Key type .llcrypt unregistered [ 6098.301816] Key type ._llcrypt unregistered