[ 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-0x00000000bffd9fff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffda000-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 1389273916 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2421 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22BD 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 00227D (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2331 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23C1 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE23F9 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22bd-0xbffe2330] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22bc] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2331-0xbffe23c0] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23c1-0xbffe23f8] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe23f9-0xbffe2420] [ 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-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 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 0xbffda000-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: 1059618 [ 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: 2895288K/4306400K 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.001020] APIC: Switch to symmetric I/O mode setup [ 0.003571] x2apic enabled [ 0.004014] Switched APIC routing to physical x2apic. [ 0.005019] kvm-guest: setup PV IPIs [ 0.011000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.011000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.012028] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.013016] pid_max: default: 32768 minimum: 301 [ 0.015201] LSM: Security Framework initializing [ 0.016085] Yama: becoming mindful. [ 0.017063] SELinux: Initializing. [ 0.018124] *** VALIDATE selinux *** [ 0.035383] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.046223] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.047228] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.049032] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.050154] *** VALIDATE tmpfs *** [ 0.052233] *** VALIDATE proc *** [ 0.053359] *** VALIDATE cgroup *** [ 0.054016] *** VALIDATE cgroup2 *** [ 0.056250] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.057283] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.058015] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.059049] Spectre V2 : User space: Vulnerable [ 0.060017] Speculative Store Bypass: Vulnerable [ 0.065555] debug: unmapping init [mem 0xffffffff8f059000-0xffffffff8f060fff] [ 0.069718] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.071227] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.072035] ... version: 2 [ 0.073019] ... bit width: 48 [ 0.074018] ... generic registers: 4 [ 0.075017] ... value mask: 0000ffffffffffff [ 0.076021] ... max period: 00007fffffffffff [ 0.077021] ... fixed-purpose events: 3 [ 0.078018] ... event mask: 000000070000000f [ 0.079575] rcu: Hierarchical SRCU implementation. [ 0.083613] smp: Bringing up secondary CPUs ... [ 0.085000] x86: Booting SMP configuration: [ 0.085047] .... node #0, CPUs: #1 #2 #3 [ 0.098607] smp: Brought up 1 node, 4 CPUs [ 0.100042] smpboot: Max logical packages: 1 [ 0.101135] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.174167] node 0 deferred pages initialised in 69ms [ 0.187503] devtmpfs: initialized [ 0.191533] x86/mm: Memory block size: 128MB [ 0.204120] gcov: version magic: 0x41383552 [ 0.210000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.231153] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.242747] pinctrl core: initialized pinctrl subsystem [ 0.251675] [ 0.253163] ************************************************************* [ 0.262017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.271021] ** ** [ 0.279015] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.289027] ** ** [ 0.297018] ** This means that this kernel is built to expose internal ** [ 0.306021] ** IOMMU data structures, which may compromise security on ** [ 0.330021] ** your system. ** [ 0.340019] ** ** [ 0.347021] ** If you see this message and you are not debugging the ** [ 0.354027] ** kernel, report this immediately to your vendor! ** [ 0.361016] ** ** [ 0.368020] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.375019] ************************************************************* [ 0.391565] NET: Registered protocol family 16 [ 0.394000] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.394000] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.394000] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.395808] cpuidle: using governor menu [ 0.429099] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.453000] PCI: Using configuration type 1 for base access [ 0.470000] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.638216] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.648246] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.661298] cryptd: max_cpu_qlen set to 1000 [ 0.668000] ACPI: Added _OSI(Module Device) [ 0.675275] ACPI: Added _OSI(Processor Device) [ 0.683019] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.689019] ACPI: Added _OSI(Processor Aggregator Device) [ 0.705000] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.726054] ACPI: Interpreter enabled [ 0.734102] ACPI: PM: (supports S0 S3 S4 S5) [ 0.746022] ACPI: Using IOAPIC for interrupt routing [ 0.756477] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.770528] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.807000] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.812057] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.825028] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.836109] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.846000] acpiphp: Slot [2] registered [ 0.846000] acpiphp: Slot [5] registered [ 0.846000] acpiphp: Slot [6] registered [ 0.846000] acpiphp: Slot [3] registered [ 0.846000] acpiphp: Slot [4] registered [ 0.846000] acpiphp: Slot [7] registered [ 0.852187] acpiphp: Slot [8] registered [ 0.856176] acpiphp: Slot [9] registered [ 0.860437] acpiphp: Slot [10] registered [ 0.865415] acpiphp: Slot [11] registered [ 0.869705] acpiphp: Slot [12] registered [ 0.874367] acpiphp: Slot [13] registered [ 0.879175] acpiphp: Slot [14] registered [ 0.885341] acpiphp: Slot [15] registered [ 0.892623] acpiphp: Slot [16] registered [ 0.898807] acpiphp: Slot [17] registered [ 0.903708] acpiphp: Slot [18] registered [ 0.910205] acpiphp: Slot [19] registered [ 0.914665] acpiphp: Slot [20] registered [ 0.919303] acpiphp: Slot [21] registered [ 0.924156] acpiphp: Slot [22] registered [ 0.929147] acpiphp: Slot [23] registered [ 0.934548] acpiphp: Slot [24] registered [ 0.940146] acpiphp: Slot [25] registered [ 0.947000] acpiphp: Slot [26] registered [ 0.955000] acpiphp: Slot [27] registered [ 0.962784] acpiphp: Slot [28] registered [ 0.970201] acpiphp: Slot [29] registered [ 0.976754] acpiphp: Slot [30] registered [ 0.983489] acpiphp: Slot [31] registered [ 0.990109] PCI host bridge to bus 0000:00 [ 0.996030] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 1.007036] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 1.016044] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 1.026032] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 1.036033] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 1.048044] pci_bus 0000:00: root bus resource [bus 00-ff] [ 1.058736] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 1.073927] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 1.087605] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 1.112000] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 1.123466] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 1.130025] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 1.139024] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 1.150024] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 1.162733] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 1.172870] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 1.182079] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 1.193194] pci 0000:00:01.3: quirk_piix4_acpi+0x0/0x1e0 took 20507 usecs [ 1.205000] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 1.212000] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 1.234000] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 1.247000] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 1.261796] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 1.274000] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 1.313000] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 1.378000] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 1.392930] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 1.401000] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 1.412000] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 1.436000] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 1.458923] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 1.465184] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 1.471525] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 1.477504] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 1.482341] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 1.492185] iommu: Default domain type: Passthrough [ 1.495041] SCSI subsystem initialized [ 1.497188] ACPI: bus type USB registered [ 1.498704] usbcore: registered new interface driver usbfs [ 1.499340] usbcore: registered new interface driver hub [ 1.500198] usbcore: registered new device driver usb [ 1.501688] pps_core: LinuxPPS API ver. 1 registered [ 1.502064] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 1.503158] PTP clock support registered [ 1.505351] EDAC MC: Ver: 3.0.0 [ 1.509115] PCI: Using ACPI for IRQ routing [ 1.514000] NetLabel: Initializing [ 1.518015] NetLabel: domain hash size = 128 [ 1.529057] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 1.546189] NetLabel: unlabeled traffic allowed by default [ 1.568165] vgaarb: loaded [ 1.575153] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.595227] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.611838] clocksource: Switched to clocksource kvm-clock [ 2.142695] VFS: Disk quotas dquot_6.6.0 [ 2.161976] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 2.286703] *** VALIDATE ramfs *** [ 2.303075] *** VALIDATE hugetlbfs *** [ 2.311681] pnp: PnP ACPI init [ 2.324760] pnp: PnP ACPI: found 6 devices [ 2.491349] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 2.514592] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 2.535377] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 2.556283] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 2.582161] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 2.612711] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 2.655057] NET: Registered protocol family 2 [ 2.676828] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 2.713847] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 2.731029] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 2.753591] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 2.778058] TCP: Hash tables configured (established 65536 bind 65536) [ 2.795812] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 2.815764] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 2.831169] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 2.849882] NET: Registered protocol family 1 [ 2.868310] RPC: Registered named UNIX socket transport module. [ 2.889650] RPC: Registered udp transport module. [ 2.907395] RPC: Registered tcp transport module. [ 2.924423] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 2.950424] NET: Registered protocol family 44 [ 2.971838] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 2.995165] pci 0000:00:00.0: quirk_natoma+0x0/0x20 took 22780 usecs [ 3.020213] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 3.045226] pci 0000:00:00.0: quirk_passive_release+0x0/0x90 took 24487 usecs [ 3.070137] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 3.102579] pci 0000:00:01.0: quirk_isa_dma_hangs+0x0/0x20 took 31682 usecs [ 3.127657] PCI: CLS 0 bytes, default 64 [ 3.142324] Unpacking initramfs... [ 3.520028] hrtimer: interrupt took 2650993 ns [ 11.702813] debug: unmapping init [mem 0xffff97ee3cc64000-0xffff97ee3ffcffff] [ 11.718801] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 11.735988] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 11.787093] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 20.690221] Initialise system trusted keyrings [ 20.729681] Key type blacklist registered [ 20.756519] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 20.860415] zbud: loaded [ 20.919209] *** VALIDATE nfs *** [ 20.932192] *** VALIDATE nfs4 *** [ 20.942098] pstore: using deflate compression [ 21.153376] Platform Keyring initialized [ 22.586388] NET: Registered protocol family 38 [ 22.606211] Key type asymmetric registered [ 22.609561] Asymmetric key parser 'x509' registered [ 22.634448] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 22.659870] io scheduler mq-deadline registered [ 22.670628] io scheduler kyber registered [ 22.683610] io scheduler bfq registered [ 22.692883] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 22.703513] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 22.717872] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 22.728745] ACPI: Power Button [PWRF] [ 22.755851] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 22.797954] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 22.852871] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 22.907698] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 22.977703] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 23.033623] Non-volatile memory driver v1.3 [ 23.044690] Linux agpgart interface v0.103 [ 23.454291] virtio_blk virtio1: [vda] 134008 512-byte logical blocks (68.6 MB/65.4 MiB) [ 23.513095] vda: detected capacity change from 0 to 68612096 [ 23.750713] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 23.778262] vdb: detected capacity change from 0 to 1073741824 [ 23.838338] libphy: Fixed MDIO Bus: probed [ 23.953394] usbcore: registered new interface driver usbserial_generic [ 23.990797] usbserial: USB Serial support registered for generic [ 24.009608] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 24.092846] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 24.118869] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 24.142846] mousedev: PS/2 mouse device common for all mice [ 24.205432] rtc_cmos 00:05: RTC can wake from S4 [ 24.240831] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 24.253161] rtc_cmos 00:05: registered as rtc0 [ 24.265966] hpet1: lost 1 rtc interrupts [ 24.292567] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 24.311779] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 24.324154] intel_pstate: CPU model not supported [ 24.376075] hid: raw HID events driver (C) Jiri Kosina [ 24.376797] usbcore: registered new interface driver usbhid [ 24.376801] usbhid: USB HID core driver [ 24.376930] drop_monitor: Initializing network drop monitor service [ 24.377125] Initializing XFRM netlink socket [ 24.378010] NET: Registered protocol family 10 [ 24.409045] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 24.444477] Segment Routing with IPv6 [ 24.576351] NET: Registered protocol family 17 [ 24.584735] mpls_gso: MPLS GSO support [ 24.650796] RAS: Correctable Errors collector initialized. [ 24.684248] AVX version of gcm_enc/dec engaged. [ 24.699937] AES CTR mode by8 optimization enabled [ 25.392877] registered taskstats version 1 [ 25.409720] Loading compiled-in X.509 certificates [ 25.430055] zswap: loaded using pool lzo/zbud [ 25.661301] Key type big_key registered [ 25.761248] Key type encrypted registered [ 25.772540] ima: No TPM chip found, activating TPM-bypass! [ 25.792910] ima: Allocated hash algorithm: sha1 [ 25.804592] ima: No architecture policies found [ 25.815596] evm: Initialising EVM extended attributes: [ 25.844044] evm: security.selinux [ 25.857568] evm: security.ima [ 25.866098] evm: security.capability [ 25.884387] evm: HMAC attrs: 0x1 [ 25.908744] rtc_cmos 00:05: setting system clock to 2026-04-24 15:09:42 UTC (1777043382) [ 25.938165] Unstable clock detected, switching default tracing clock to "global" [ 25.938165] If you want to keep using the local clock, then add: [ 25.938165] "trace_clock=local" [ 25.938165] on the kernel command line [ 26.050256] debug: unmapping init [mem 0xffffffff90003000-0xffffffff901fffff] [ 26.113004] debug: unmapping init [mem 0xffffffff8ed82000-0xffffffff8f058fff] [ 26.142361] Write protecting the kernel read-only data: 28672k [ 26.176522] debug: unmapping init [mem 0xffffffff8d403000-0xffffffff8d5fffff] [ 26.199738] debug: unmapping init [mem 0xffffffff8dd14000-0xffffffff8ddfffff] [ 26.640178] 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) [ 26.760153] systemd[1]: Detected virtualization kvm. [ 26.781430] systemd[1]: Detected architecture x86-64. [ 26.809681] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 27.045490] systemd[1]: No hostname configured. [ 27.075187] systemd[1]: Set hostname to . [ 27.099046] random: systemd: uninitialized urandom read (16 bytes read) [ 27.133571] systemd[1]: Initializing machine ID from random generator. [ 27.671689] random: ln: uninitialized urandom read (6 bytes read) [ 28.619354] random: systemd: uninitialized urandom read (16 bytes read) [ 28.703381] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 28.824030] random: systemd: uninitialized urandom read (16 bytes read) [ 28.852453] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 28.952043] random: systemd: uninitialized urandom read (16 bytes read) [ 29.004147] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Slices. [ OK ] Reached target Swap. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Journal Service... Starting Create Volatile Files and Directories... Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Reached target Paths. [ OK ] Listening on udev Control Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Initrd Root Device. Starting Setup Virtual Console... [ OK ] Reached target Timers. [ 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. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ 32.146007] systemd[1]: Started Journal Service. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 35.388854] device-mapper: uevent: version 1.0.3 [ 35.435566] 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. [ 41.012023] random: fast init done Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 41.717008] virtio_net virtio0 ens2: renamed from eth0 [ 42.079171] scsi host0: ata_piix [ 42.492918] scsi host1: ata_piix [ 42.515988] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 42.561171] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 50.420006] random: crng init done [ 50.425028] random: 5 urandom warning(s) missed due to ratelimiting [ 57.957977] dracut-initqueue[587]: 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... [ 64.504603] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ 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 Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ 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 ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 78.166447] printk: systemd: 25 output lines suppressed due to ratelimiting [ 80.572388] SELinux: Disabled at runtime. [ 81.164166] 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) [ 81.250459] systemd[1]: Detected virtualization kvm. [ 81.265423] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 87.178147] systemd[1]: initrd-switch-root.service: Succeeded. [ 87.215907] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 87.315510] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 87.370048] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 87.422213] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 87.571259] systemd[1]: Starting Journal Service... Starting Journal Service... [ 87.660089] systemd[1]: Listening on initctl Compatibility Named Pipe. [ OK ] Listening on initctl Compatibility Named Pipe. [ 87.768835] systemd[1]: Listening on RPCbind Server Activation Socket. [ OK ] Listening on RPCbind Server Activation Socket. [ 87.858799] systemd[1]: Created slice system-getty.slice. [ OK ] Created slice system-getty.slice. [ 87.949260] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. Mounting POSIX Message Queue File System... [ OK ] Reached target Slices. Starting Apply Kernel Variables... Mounting Kernel Debug File System... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on udev Kernel Socket. Starting Create list of required st…ce nodes for the current kernel... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on udev Control Socket. Starting Remount Root and Kernel File Systems... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target L[ 89.524404] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS ocal Encrypted Volumes. [ OK ] Reached target Paths. Mounting Huge Pages File System... [ OK ] Listening on Process Core Dump Socket. Starting udev Coldplug all Devices... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. [ OK ] Reached target rpc_pipefs.target. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Activated swap /dev/disk/by-label/SWAP. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Huge Pages File System. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 94.021973] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 98.848867] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 99.572938] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 101.172923] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 101.500068] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…only root support (16s / no limit) [** ] A start job is running for Configur…only root support (16s / no limit) [*** ] A start job is running for Configur…only root support (17s / no limit) [ *** ] A start job is running for Configur…only root support (17s / no limit) [ *** ] A start job is running for Configur…only root support (18s / no limit) [ ***] A start job is running for Configur…only root support (18s / no limit) [ **] A start job is running for Configur…only root support (19s / no limit) [ *] A start job is running for Configur…only root support (19s / no limit) [ **] A start job is running for Configur…only root support (20s / no limit) [ ***] A start job is running for Configur…only root support (20s / no limit) [ *** ] A start job is running for Configur…only root support (21s / no limit) [ *** ] A start job is running for Configur…only root support (21s / no limit) [*** ] A start job is running for Configur…only root support (22s / no limit) [** ] A start job is running for Configur…only root support (22s / no limit) [* ] A start job is running for Configur…only root support (23s / no limit) [** ] A start job is running for Configur…only root support (23s / no limit) [*** ] A start job is running for Configur…only root support (24s / no limit) [ *** ] A start job is running for Configur…only root support (24s / no limit) [ *** ] A start job is running for Configur…only root support (25s / no limit) [ ***] A start job is running for Configur…only root support (25s / no limit) [ **] A start job is running for Configur…only root support (26s / no limit) [ *] A start job is running for Configur…only root support (26s / no limit) [ **] A start job is running for Configur…only root support (27s / no limit) [ ***] A start job is running for Configur…only root support (27s / no limit) [ *** ] A start job is running for Configur…only root support (28s / no limit) [ *** ] A start job is running for Configur…only root support (28s / no limit) [*** ] A start job is running for Configur…only root support (29s / no limit) [** ] A start job is running for Configur…only root support (29s / no limit) [* ] A start job is running for Configur…only root support (30s / no limit) [** ] A start job is running for Configur…only root support (30s / no limit) [*** ] A start job is running for Configur…only root support (31s / no limit) [ *** ] A start job is running for Configur…only root support (31s / no limit) [ *** ] A start job is running for Configur…only root support (32s / no limit) [ ***] A start job is running for Configur…only root support (33s / no limit)[ 120.713853] Key type dns_resolver registered [ **] A start job is running for Configur…only root support (34s / no limit) [ *] A start job is running for Configur…only root support (34s / no limit) [ **] A start job is running for Configur…only root support (35s / no limit) [ ***] A start job is running for Configur…only root support (35s / no limit) [ *** ] A start job is running for Configur…only root support (36s / no limit) [ *** ] A start job is running for Configur…only root support (36s / no limit) [*** ] A start job is running for Configur…only root support (37s / no limit) [** ] A start job is running for Configur…only root support (37s / no limit) [* ] A start job is running for Configur…only root support (38s / no limit) [** ] A start job is running for Configur…only root support (38s / no limit) [*** ] A start job is running for Configur…only root support (39s / no limit)[ 126.108200] NFS: Registering the id_resolver key type [ 126.149404] Key type id_resolver registered [ 126.170811] Key type id_legacy registered [ *** ] A start job is running for Configur…only root support (39s / no limit) [ *** ] A start job is running for Configur…only root support (40s / no limit) [ ***] A start job is running for Configur…only root support (40s / no limit) [ **] A start job is running for Configur…only root support (41s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Load/Save Random Seed... Starting Create Volatile Files and Directories... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ *] A start job is running for Rebuild …amic Linker Cache (49s / no limit) [ **] A start job is running for Rebuild …amic Linker Cache (50s / no limit) [ ***] A start job is running for Rebuild …amic Linker Cache (50s / no limit) [ *** ] A start job is running for Rebuild …amic Linker Cache (51s / no limit) [ *** ] A start job is running for Rebuild …amic Linker Cache (51s / no limit) [ 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 ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... Starting Hostname Service... [*** ] (4 of 5) A start job is running for…Tuning Daemon (1min 1s / 2min 26s) [** ] (4 of 5) A start job is running for…Tuning Daemon (1min 2s / 2min 26s) [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg159-client login: [ 342.826102] libcfs: loading out-of-tree module taints kernel. [ 343.088341] Key type ._llcrypt registered [ 343.093834] Key type .llcrypt registered [ 345.713961] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 345.802702] alg: No test for adler32 (adler32-zlib) [ 349.783537] Lustre: Lustre: Build Version: 2.17.52_54_g344a3c0 [ 353.283877] LNet: Added LNI 192.168.201.59@tcp [8/256/0/180] [ 355.632220] Key type lgssc registered [ 361.581909] Lustre: Echo OBD driver; http://www.lustre.org/ [ 713.464400] Lustre: Mounted lustre-client [ 728.935667] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 738.786542] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 20s idle [ 770.115085] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing check_logdir /tmp/testlogs/ [ 786.572829] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing yml_node [ 799.976011] Lustre: DEBUG MARKER: Client: 2.17.52.54 [ 810.077153] Lustre: DEBUG MARKER: MDS: 2.17.52.54 [ 818.561009] Lustre: DEBUG MARKER: OSS: 2.17.52.54 [ 824.034287] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Fri Apr 24 11:22:55 EDT 2026 [ 877.430155] Lustre: DEBUG MARKER: excepting tests: 27 40a 102 [ 881.724993] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 887.518692] Lustre: DEBUG MARKER: === sanityn: start setup 11:23:58 (1777044238) === [ 889.667510] Lustre: Mounted lustre-client [ 902.766360] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing check_config_client /mnt/lustre [ 954.255955] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 986.962246] Lustre: DEBUG MARKER: === sanityn: finish setup 11:25:38 (1777044338) === [ 994.435218] Lustre: DEBUG MARKER: == sanityn test 0: do_node_vp() and do_facet_vp() do the right thing ========================================================== 11:25:46 (1777044346) [ 1012.705309] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 24s idle [ 1012.776426] Lustre: Skipped 1 previous similar message [ 1021.471241] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 11:26:13 (1777044373) [ 1043.425661] Lustre: lustre-OST0001-osc-ffff97ee87d59000: disconnect after 20s idle [ 1045.461548] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 11:26:36 (1777044396) [ 1069.280054] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 11:27:00 (1777044420) [ 1089.714381] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 11:27:21 (1777044441) [ 1110.526563] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 11:27:42 (1777044462) [ 1130.331281] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 11:28:01 (1777044481) [ 1150.093335] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 11:28:22 (1777044502) [ 1155.707516] Lustre: DEBUG MARKER: SKIP: sanityn test_2f needs >= 2 MDTs [ 1161.565529] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 11:28:33 (1777044513) [ 1183.813802] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 11:28:55 (1777044535) [ 1186.793308] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 24s idle [ 1186.825316] Lustre: Skipped 1 previous similar message [ 1204.566610] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 11:29:16 (1777044556) [ 1227.042541] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 11:29:37 (1777044577) [ 1227.749708] Lustre: lustre-OST0000-osc-ffff97ee89f26000: disconnect after 22s idle [ 1227.786286] Lustre: Skipped 2 previous similar messages [ 1250.773536] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 11:30:02 (1777044602) [ 1272.527009] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 11:30:24 (1777044624) [ 1278.945761] Lustre: lustre-OST0001-osc-ffff97ee87d59000: disconnect after 24s idle [ 1295.914816] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 11:30:47 (1777044647) [ 1318.507119] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 11:31:10 (1777044670) [ 1342.039826] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 11:31:34 (1777044694) [ 1364.582283] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 11:31:57 (1777044717) [ 1392.968177] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 11:32:24 (1777044744) [ 1416.500462] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 11:32:48 (1777044768) [ 1440.254813] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 11:33:11 (1777044791) [ 1442.138798] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205272502301 file: /mnt/lustre/lockdir/lockfile=144115205272502299 [ 1612.673540] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 11:36:04 (1777044964) [ 1646.194434] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 11:36:37 (1777044997) [ 1670.262643] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 11:37:01 (1777045021) [ 1694.215485] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 11:37:25 (1777045045) [ 1718.292294] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 11:37:50 (1777045070) [ 1743.686266] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 11:38:15 (1777045095) [ 1752.120294] Lustre: DEBUG MARKER: chmod [ 1779.857310] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 11:38:49 (1777045129) [ 1790.944707] Lustre: lustre-OST0001-osc-ffff97ee89f26000: disconnect after 21s idle [ 1866.154873] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7531520KB free > 800000KB, increase MAXFREE (or reduce fs size) [ 1883.104725] Lustre: lustre-OST0001-osc-ffff97ee89f26000: disconnect after 23s idle [ 1909.322661] Lustre: DEBUG MARKER: == sanityn test 16a: 500 iterations of dual-mount fsx ==== 11:41:00 (1777045260) [ 2046.949163] Lustre: lustre-OST0001-osc-ffff97ee89f26000: disconnect after 24s idle [ 2125.161664] Lustre: DEBUG MARKER: == sanityn test 16b: 500 iterations of dual-mount fsx at small size ========================================================== 11:44:36 (1777045476) [ 2246.836895] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 11:46:38 (1777045598) [ 2256.197406] Lustre: DEBUG MARKER: SKIP: sanityn test_16c dio on ldiskfs only [ 2262.842429] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 11:46:53 (1777045613) [ 2292.705791] Lustre: lustre-OST0000-osc-ffff97ee89f26000: disconnect after 22s idle [ 2439.549309] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 11:49:51 (1777045791) [ 2459.637300] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 11:50:11 (1777045811) [ 2463.428177] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2463.737046] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2464.029522] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2464.334659] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2464.532738] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2464.747633] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2465.067355] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2465.245377] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2465.486159] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2465.833840] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2466.103732] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2466.361101] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2466.701495] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2467.045435] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2467.360534] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2467.724012] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2468.079456] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2468.300016] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2468.576127] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2468.862776] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2469.187900] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2469.467824] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2469.688009] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2469.986915] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2470.351007] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2470.594363] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2470.896492] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2471.222336] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2471.495390] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2471.838831] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2472.118088] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2472.379800] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2472.591905] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2472.880116] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2473.053764] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2473.381065] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2473.652828] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2474.036356] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2474.290954] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2474.621848] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2474.886247] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2475.113465] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2475.416881] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2475.687929] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2475.947061] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2476.278917] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2476.583896] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2476.807885] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2477.010749] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2477.300534] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2477.506349] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2477.811280] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2478.025329] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2478.266985] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2478.423829] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2478.770044] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2479.007907] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2479.262005] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2479.577859] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2479.882013] rw_seq_cst_vs_d (29734): drop_caches: 3 [ 2503.282324] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 11:50:54 (1777045854) [ 2505.092439] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2505.325282] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2505.530328] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2506.004042] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2506.423592] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2506.564947] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2506.933586] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2507.231482] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2507.446966] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2507.682208] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2507.913957] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2508.310339] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2508.495396] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2508.689708] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2508.909335] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2509.128012] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2509.249209] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2509.586278] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2509.903247] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2510.209504] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2510.421241] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2510.533795] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2511.146192] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2511.377167] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2511.622017] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2511.873283] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2512.002076] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2512.336922] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2512.563562] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2512.825215] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2513.081433] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2513.409080] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2513.569918] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2513.698899] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2514.169460] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2514.690328] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2515.012160] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2515.215662] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2515.451136] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2515.722222] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2516.140364] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2516.442869] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2516.645963] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2516.910880] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2517.055314] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2517.456117] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2517.878400] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2518.421318] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2518.630967] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2518.987671] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2519.211886] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2519.481279] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2519.820723] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2520.055978] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2520.419104] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2520.511063] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2520.889096] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2521.297566] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2521.482471] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2521.629487] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2521.815797] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2522.106503] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2522.782634] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2523.018639] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2523.308478] rw_seq_cst_vs_d (30312): drop_caches: 3 [ 2545.334191] Lustre: DEBUG MARKER: == sanityn test 16h: mmap read after truncate file ======= 11:51:37 (1777045897) [ 2566.862317] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 11:51:59 (1777045919) [ 2569.185479] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 21s idle [ 2569.201705] Lustre: Skipped 12 previous similar messages [ 2588.372617] Lustre: DEBUG MARKER: == sanityn test 16j: race dio with buffered i/o ========== 11:52:20 (1777045940) [ 2743.221879] Lustre: DEBUG MARKER: == sanityn test 16k: Parallel FSX and drop caches should not panic ========================================================== 11:54:54 (1777046094) [ 2743.984012] bash (32774): drop_caches: 3 [ 2752.241613] bash (32774): drop_caches: 3 [ 2758.621261] bash (32774): drop_caches: 3 [ 2762.082044] bash (32774): drop_caches: 3 [ 2766.197677] bash (32774): drop_caches: 3 [ 2770.134279] bash (32774): drop_caches: 3 [ 2775.291526] bash (32774): drop_caches: 3 [ 2778.672422] bash (32774): drop_caches: 3 [ 2782.074876] bash (32774): drop_caches: 3 [ 2786.602730] bash (32774): drop_caches: 3 [ 2790.220962] bash (32774): drop_caches: 3 [ 2793.715629] bash (32774): drop_caches: 3 [ 2797.267488] bash (32774): drop_caches: 3 [ 2800.730740] bash (32774): drop_caches: 3 [ 2804.123491] bash (32774): drop_caches: 3 [ 2807.481644] bash (32774): drop_caches: 3 [ 2810.997513] bash (32774): drop_caches: 3 [ 2814.480567] bash (32774): drop_caches: 3 [ 2817.824916] bash (32774): drop_caches: 3 [ 2821.318509] bash (32774): drop_caches: 3 [ 2824.634211] bash (32774): drop_caches: 3 [ 2828.081157] bash (32774): drop_caches: 3 [ 2831.541611] bash (32774): drop_caches: 3 [ 2834.983278] bash (32774): drop_caches: 3 [ 2838.528994] bash (32774): drop_caches: 3 [ 2842.036662] bash (32774): drop_caches: 3 [ 2845.369409] bash (32774): drop_caches: 3 [ 2848.820539] bash (32774): drop_caches: 3 [ 2852.270460] bash (32774): drop_caches: 3 [ 2855.664723] bash (32774): drop_caches: 3 [ 2859.144821] bash (32774): drop_caches: 3 [ 2862.592950] bash (32774): drop_caches: 3 [ 2866.304070] bash (32774): drop_caches: 3 [ 2869.597410] bash (32774): drop_caches: 3 [ 2873.080761] bash (32774): drop_caches: 3 [ 2876.660337] bash (32774): drop_caches: 3 [ 2880.057531] bash (32774): drop_caches: 3 [ 2883.471500] bash (32774): drop_caches: 3 [ 2886.908283] bash (32774): drop_caches: 3 [ 2890.461392] bash (32774): drop_caches: 3 [ 2894.178885] bash (32774): drop_caches: 3 [ 2897.720712] bash (32774): drop_caches: 3 [ 2901.478957] bash (32774): drop_caches: 3 [ 2904.928039] bash (32774): drop_caches: 3 [ 2908.270598] bash (32774): drop_caches: 3 [ 2911.829858] bash (32774): drop_caches: 3 [ 2915.369520] bash (32774): drop_caches: 3 [ 2919.040832] bash (32774): drop_caches: 3 [ 2928.422268] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 11:57:59 (1777046279) [ 2956.627799] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 11:58:28 (1777046308) [ 3021.624721] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 11:59:33 (1777046373) [ 3029.319823] Lustre: DEBUG MARKER: SKIP: sanityn test_19 not cache-capable obdfilter [ 3034.163566] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 11:59:46 (1777046386) [ 3057.298873] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 12:00:09 (1777046409) [ 3079.596332] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 12:00:31 (1777046431) [ 3105.760993] Lustre: lustre-OST0001-osc-ffff97ee87d59000: disconnect after 22s idle [ 3105.784348] Lustre: Skipped 8 previous similar messages [ 3169.253462] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 12:02:01 (1777046521) [ 3196.502017] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 12:02:28 (1777046548) [ 3218.698405] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 12:02:49 (1777046569) [ 3243.053942] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 12:03:14 (1777046594) [ 3248.476635] Lustre: DEBUG MARKER: SKIP: sanityn test_25b needs >= 2 MDTs [ 3254.003793] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 12:03:26 (1777046606) [ 3276.682816] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 12:03:49 (1777046629) [ 3302.328871] Lustre: DEBUG MARKER: == sanityn test 26c: set-in-past on open file is not lost on close ========================================================== 12:04:14 (1777046654) [ 3323.239842] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 3329.443012] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 12:04:41 (1777046681) [ 3353.448593] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 12:05:05 (1777046705) [ 3354.310822] Lustre: *** cfs_fail_loc=314, val=0*** [ 3355.424335] Lustre: *** cfs_fail_loc=314, val=0*** [ 3355.437669] Lustre: Skipped 2 previous similar messages [ 3373.762061] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 12:05:26 (1777046726) [ 3400.250770] Lustre: *** cfs_fail_loc=314, val=0*** [ 3400.653891] LustreError: lustre-OST0000-osc-ffff97ee89f26000: operation ldlm_enqueue to node 192.168.201.159@tcp failed: rc = -107 [ 3400.704524] Lustre: lustre-OST0000-osc-ffff97ee89f26000: Connection to lustre-OST0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3400.842617] LustreError: lustre-OST0000-osc-ffff97ee89f26000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 3400.941111] LustreError: 42147:0:(ldlm_resource.c:1172:ldlm_resource_complain()) lustre-OST0000-osc-ffff97ee89f26000: namespace resource [0x240000400:0x35:0x0].0x0 (ffff97ee82898600) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 3401.090791] Lustre: lustre-OST0000-osc-ffff97ee89f26000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [ 3424.431714] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 12:06:16 (1777046776) [ 3426.159496] LustreError: 42731:0:(file.c:817:ll_intent_file_open()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 3429.208724] LustreError: 42731:0:(file.c:817:ll_intent_file_open()) cfs_fail_timeout id 1419 awake [ 3449.023201] Lustre: DEBUG MARKER: == sanityn test 31s: open should not revalidate invalid dentry ========================================================== 12:06:41 (1777046801) [ 3470.220651] Lustre: DEBUG MARKER: == sanityn test 31t: getattr should not revalidate invalid dentry ========================================================== 12:07:02 (1777046822) [ 3490.996588] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 3497.472866] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 12:07:28 (1777046848) [ 3502.201135] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 3507.898978] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-on-Lock-Cancel ========================================================== 12:07:39 (1777046859) [ 3512.595948] Lustre: DEBUG MARKER: SKIP: sanityn test_33c needs >= 2 MDTs [ 3517.869796] Lustre: DEBUG MARKER: == sanityn test 33d: dependent transactions should trigger COS ========================================================== 12:07:49 (1777046869) [ 3522.858079] Lustre: DEBUG MARKER: SKIP: sanityn test_33d needs >= 2 MDTs [ 3528.391980] Lustre: DEBUG MARKER: == sanityn test 33e: independent transactions shouldn't trigger COS ========================================================== 12:08:00 (1777046880) [ 3533.448834] Lustre: DEBUG MARKER: SKIP: sanityn test_33e needs >= 2 MDTs [ 3539.154339] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 12:08:10 (1777046890) [ 3609.528473] Lustre: lustre-OST0001-osc-ffff97ee89f26000: Connection to lustre-OST0001 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3609.628301] LustreError: lustre-OST0001-osc-ffff97ee87d59000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 3609.701658] LustreError: lustre-OST0001-osc-ffff97ee89f26000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 3609.706462] Lustre: lustre-OST0001-osc-ffff97ee87d59000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [ 3609.766920] Lustre: Skipped 1 previous similar message [ 3631.123064] Lustre: lustre-OST0000-osc-ffff97ee87d59000: Connection to lustre-OST0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3631.177027] Lustre: Skipped 1 previous similar message [ 3631.223258] LustreError: lustre-OST0000-osc-ffff97ee87d59000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 3631.312686] Lustre: lustre-OST0000-osc-ffff97ee87d59000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [ 3659.785433] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff97ee87d59000.ost_server_uuid 50 [ 3664.221591] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff97ee87d59000.ost_server_uuid in IDLE state after 0 sec [ 3676.087691] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff97ee87d59000.ost_server_uuid 50 [ 3681.000102] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff97ee87d59000.ost_server_uuid in IDLE state after 0 sec [ 3696.890018] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff97ee87d59000.ost_server_uuid 50 [ 3701.601140] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff97ee87d59000.ost_server_uuid in IDLE state after 0 sec [ 3713.732081] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff97ee87d59000.ost_server_uuid 50 [ 3718.357146] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff97ee87d59000.ost_server_uuid in IDLE state after 0 sec [ 3748.869266] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff97ee87d59000.ost_server_uuid 50 [ 3753.750727] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff97ee87d59000.ost_server_uuid in IDLE state after 0 sec [ 3766.158281] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff97ee87d59000.ost_server_uuid 50 [ 3770.800443] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff97ee87d59000.ost_server_uuid in IDLE state after 0 sec [ 3776.306223] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 12:12:08 (1777047128) [ 3783.474367] Lustre: DEBUG MARKER: Race attempt 0 [ 3789.978737] Lustre: DEBUG MARKER: Wait for 49386 49405 for 60 sec... [ 3982.083717] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 12:15:34 (1777047334) [ 3997.039012] Lustre: DEBUG MARKER: start test - cycle (0) [ 4035.553839] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 22s idle [ 4035.591197] Lustre: Skipped 11 previous similar messages [ 4040.638680] Lustre: DEBUG MARKER: start test - cycle (1) [ 4083.323624] Lustre: DEBUG MARKER: start test - cycle (2) [ 4123.338241] Lustre: DEBUG MARKER: start test - cycle (3) [ 4163.754740] Lustre: DEBUG MARKER: start test - cycle (4) [ 4205.281205] Lustre: DEBUG MARKER: start test - cycle (5) [ 4244.797274] Lustre: DEBUG MARKER: start test - cycle (6) [ 4284.034840] Lustre: DEBUG MARKER: start test - cycle (7) [ 4326.804706] Lustre: DEBUG MARKER: start test - cycle (8) [ 4365.609868] Lustre: DEBUG MARKER: start test - cycle (9) [ 4406.127231] Lustre: DEBUG MARKER: start test - cycle (10) [ 4465.642214] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 12:23:38 (1777047818) [ 4681.266146] Lustre: DEBUG MARKER: == sanityn test 39a: file mtime does not change after rename ========================================================== 12:27:14 (1777048034) [ 4695.989686] Lustre: DEBUG MARKER: == sanityn test 39b: file mtime the same on clients with/out lock ========================================================== 12:27:29 (1777048049) [ 4706.272259] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 22s idle [ 4706.293939] Lustre: Skipped 39 previous similar messages [ 4708.979018] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 12:27:42 (1777048062) [ 4722.792839] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 12:27:57 (1777048077) [ 4723.246815] Lustre: *** cfs_fail_loc=411, val=0*** [ 4731.878494] Lustre: DEBUG MARKER: SKIP: sanityn test_40a skipping ALWAYS excluded test 40a [ 4734.113210] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 12:28:08 (1777048088) [ 4759.010679] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 12:28:33 (1777048113) [ 4781.091394] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 12:28:54 (1777048134) [ 4803.125497] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 12:29:17 (1777048157) [ 4825.152775] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 12:29:39 (1777048179) [ 4842.660180] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 12:29:57 (1777048197) [ 4861.017074] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 12:30:15 (1777048215) [ 4879.924327] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 12:30:34 (1777048234) [ 4897.228774] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 12:30:51 (1777048251) [ 4913.997112] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 12:31:08 (1777048268) [ 4932.296683] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 12:31:26 (1777048286) [ 4950.923003] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 12:31:44 (1777048304) [ 4972.970498] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 12:32:06 (1777048326) [ 5586.913288] Lustre: lustre-OST0000-osc-ffff97ee89f26000: disconnect after 23s idle [ 5586.966011] Lustre: Skipped 13 previous similar messages [ 6147.937644] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 12:51:43 (1777049503) [ 6160.971081] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 12:51:56 (1777049516) [ 6172.647327] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 12:52:08 (1777049528) [ 6184.234767] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 12:52:19 (1777049539) [ 6195.927067] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 12:52:31 (1777049551) [ 6201.312299] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 20s idle [ 6201.333241] Lustre: Skipped 1 previous similar message [ 6207.862074] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 12:52:43 (1777049563) [ 6219.698647] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 12:52:54 (1777049574) [ 6231.279653] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 12:53:06 (1777049586) [ 6243.841220] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 12:53:19 (1777049599) [ 6301.144532] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 12:54:16 (1777049656) [ 6313.002899] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 12:54:28 (1777049668) [ 6325.528283] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 12:54:40 (1777049680) [ 6337.162458] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 12:54:52 (1777049692) [ 6348.950406] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 12:55:04 (1777049704) [ 6361.811579] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 12:55:16 (1777049716) [ 6374.495660] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 12:55:29 (1777049729) [ 6387.521602] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 12:55:42 (1777049742) [ 6389.139466] Lustre: DEBUG MARKER: SKIP: sanityn test_43i needs >= 2 MDTs [ 6391.034252] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 12:55:46 (1777049746) [ 6503.477128] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 12:57:38 (1777049858) [ 7005.152586] Lustre: lustre-OST0001-osc-ffff97ee89f26000: disconnect after 21s idle [ 7005.167201] Lustre: Skipped 5 previous similar messages [ 7578.965007] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 13:15:34 (1777050934) [ 7590.285015] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 13:15:45 (1777050945) [ 7601.791939] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 13:15:57 (1777050957) [ 7613.021124] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 13:16:08 (1777050968) [ 7624.712369] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 13:16:19 (1777050979) [ 7636.042664] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 13:16:31 (1777050991) [ 7648.134001] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 13:16:43 (1777051003) [ 7660.286602] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 13:16:55 (1777051015) [ 7660.512261] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 21s idle [ 7660.523469] Lustre: Skipped 2 previous similar messages [ 7671.622270] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 13:17:07 (1777051027) [ 7672.770496] Lustre: DEBUG MARKER: SKIP: sanityn test_44i needs >= 2 MDTs [ 7674.155843] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 13:17:09 (1777051029) [ 7765.403735] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 13:18:41 (1777051121) [ 7774.502311] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 13:18:50 (1777051130) [ 7783.561621] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 13:18:59 (1777051139) [ 7793.732292] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 13:19:09 (1777051149) [ 7803.841961] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 13:19:19 (1777051159) [ 7814.059710] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 13:19:29 (1777051169) [ 7824.688814] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 13:19:39 (1777051179) [ 7834.263568] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 13:19:49 (1777051189) [ 7835.619656] Lustre: DEBUG MARKER: SKIP: sanityn test_45i needs >= 2 MDTs [ 7837.241211] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 13:19:52 (1777051192) [ 8295.392356] Lustre: lustre-OST0001-osc-ffff97ee87d59000: disconnect after 20s idle [ 8295.404619] Lustre: Skipped 9 previous similar messages [ 8767.204063] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 13:35:22 (1777052122) [ 8778.099582] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 13:35:33 (1777052133) [ 8788.977444] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 13:35:44 (1777052144) [ 8800.037601] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 13:35:55 (1777052155) [ 8810.569509] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 13:36:06 (1777052166) [ 8819.991329] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 13:36:15 (1777052175) [ 8829.286887] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 13:36:24 (1777052184) [ 8838.918489] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 13:36:34 (1777052194) [ 8848.575742] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 13:36:44 (1777052204) [ 8849.766755] Lustre: DEBUG MARKER: SKIP: sanityn test_46i needs >= 2 MDTs [ 8850.994811] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 13:36:46 (1777052206) [ 8851.999647] Lustre: DEBUG MARKER: SKIP: sanityn test_47a needs >= 2 MDTs [ 8853.705190] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 13:36:48 (1777052208) [ 8854.742892] Lustre: DEBUG MARKER: SKIP: sanityn test_47b needs >= 2 MDTs [ 8856.008393] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 13:36:51 (1777052211) [ 8857.285008] Lustre: DEBUG MARKER: SKIP: sanityn test_47c needs >= 2 MDTs [ 8858.563531] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 13:36:54 (1777052214) [ 8859.562544] Lustre: DEBUG MARKER: SKIP: sanityn test_47d needs >= 2 MDTs [ 8860.764397] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 13:36:56 (1777052216) [ 8861.779694] Lustre: DEBUG MARKER: SKIP: sanityn test_47e needs >= 2 MDTs [ 8862.949356] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 13:36:58 (1777052218) [ 8864.059806] Lustre: DEBUG MARKER: SKIP: sanityn test_47f needs >= 2 MDTs [ 8865.243418] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 13:37:00 (1777052220) [ 8866.214431] Lustre: DEBUG MARKER: SKIP: sanityn test_47g needs >= 2 MDTs [ 8867.422681] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 13:37:03 (1777052223) [ 8867.665935] LustreError: 5599:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 sleeping for 2000ms [ 8869.768209] LustreError: 5599:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 awake [ 8877.678242] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 13:37:13 (1777052233) [ 8885.065381] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 13:37:20 (1777052240) [ 8885.365596] LustreError: 217747:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 8889.434435] LustreError: 217747:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 8889.468084] LustreError: 217747:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 8893.536795] LustreError: 217747:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 8893.604370] LustreError: 217754:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 8897.680189] LustreError: 217754:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 8902.722214] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 13:37:38 (1777052258) [ 8912.632523] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 13:37:48 (1777052268) [ 8918.224923] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 13:37:53 (1777052273) [ 8920.032419] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 21s idle [ 8920.039433] Lustre: Skipped 4 previous similar messages [ 8924.305657] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 13:38:00 (1777052280) [ 8952.049057] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 13:38:27 (1777052307) [ 8962.402841] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 13:38:37 (1777052317) [ 8973.183816] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 13:38:48 (1777052328) [ 8989.416942] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 13:39:05 (1777052345) [ 9001.203423] Lustre: DEBUG MARKER: == sanityn test 55e: rename race AB/BA under the same parent dir ========================================================== 13:39:16 (1777052356) [ 9002.404501] Lustre: DEBUG MARKER: SKIP: sanityn test_55e needs >= 2 MDTs [ 9003.882997] Lustre: DEBUG MARKER: == sanityn test 55f: rename: (P1/A -> P2/B) race with (P2/B -> P1/A) ========================================================== 13:39:19 (1777052359) [ 9019.740234] Lustre: DEBUG MARKER: == sanityn test 55g: rename: race with trylock =========== 13:39:35 (1777052375) [ 9036.787900] Lustre: DEBUG MARKER: == sanityn test 56a: test llverdev with single large stripe ========================================================== 13:39:52 (1777052392) [ 9095.787679] Lustre: DEBUG MARKER: == sanityn test 56b: test llverdev and partial verify of wide stripe file ========================================================== 13:40:51 (1777052451) [ 9164.048953] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 13:41:59 (1777052519) [ 9170.022883] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 9176.069255] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 13:42:11 (1777052531) [ 9182.432646] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 13:42:17 (1777052537) [ 9183.838210] Lustre: DEBUG MARKER: SKIP: sanityn test_71a ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 9185.070298] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 13:42:20 (1777052540) [ 9186.506686] Lustre: DEBUG MARKER: SKIP: sanityn test_71b ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 9188.004414] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 13:42:23 (1777052543) [ 9189.227201] Lustre: DEBUG MARKER: SKIP: sanityn test_71c support only ldiskfs ost [ 9190.372399] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 13:42:26 (1777052546) [ 9191.735158] Lustre: DEBUG MARKER: SKIP: sanityn test_71d ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 9193.311722] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 13:42:28 (1777052548) [ 9197.904672] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 13:42:33 (1777052553) [ 9203.305519] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 13:42:38 (1777052558) [ 9206.520491] LustreError: lustre-MDT0000-mdc-ffff97ee87d59000: operation ldlm_enqueue to node 192.168.201.159@tcp failed: rc = -35 [ 9211.260813] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 13:42:47 (1777052567) [ 9211.484454] LustreError: 2388:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d sleeping for 2000ms [ 9213.576500] LustreError: 2388:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d awake [ 9220.551740] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 13:42:56 (1777052576) [ 9259.290393] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 13:43:34 (1777052614) [ 9266.121840] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 13:43:41 (1777052621) [ 9275.461735] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 13:43:50 (1777052630) [ 9286.848844] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 13:44:02 (1777052642) [ 9298.417559] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 13:44:13 (1777052653) [ 9316.866702] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 13:44:32 (1777052672) [ 9333.385284] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 13:44:48 (1777052688) [ 9341.191723] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 13:44:56 (1777052696) [ 9349.934741] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 13:45:05 (1777052705) [ 9366.895257] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 13:45:22 (1777052722) [ 9419.039823] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 13:46:14 (1777052774) [ 9554.913286] Lustre: lustre-OST0000-osc-ffff97ee87d59000: disconnect after 21s idle [ 9554.923972] Lustre: Skipped 11 previous similar messages [ 9560.910633] Lustre: DEBUG MARKER: == sanityn test 77jb: check TBF-UID/GID NRS policy on files that don't belong to us ========================================================== 13:48:36 (1777052916) [ 9701.078825] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with UID/GID/JobID/OPCode expression ========================================================== 13:50:56 (1777053056) [10070.109346] Lustre: DEBUG MARKER: == sanityn test 77kb: Check different granular TBF type combination: jobid+opcode ========================================================== 13:57:05 (1777053425) [10111.003842] Lustre: DEBUG MARKER: == sanityn test 77kc: Check different granular TBF type combination: nid+opcode ========================================================== 13:57:46 (1777053466) [10155.285985] Lustre: DEBUG MARKER: == sanityn test 77kd: Check different granular TBF type combination: nid+jobid ========================================================== 13:58:30 (1777053510) [10179.552369] Lustre: lustre-OST0001-osc-ffff97ee87d59000: disconnect after 22s idle [10179.559877] Lustre: Skipped 17 previous similar messages [10194.624891] Lustre: DEBUG MARKER: == sanityn test 77ke: Check different granular TBF type combination: jobid+opcode ========================================================== 13:59:10 (1777053550) [10278.189308] Lustre: DEBUG MARKER: == sanityn test 77kf: Check different granular TBF type combination: uid+gid ========================================================== 14:00:33 (1777053633) [10347.005633] Lustre: DEBUG MARKER: == sanityn test 77kg: check different granular TBF type combination: uid+opcode ========================================================== 14:01:42 (1777053702) [10472.568100] Lustre: DEBUG MARKER: == sanityn test 77kh: Verify that Project ID support for NRS TBF rule ========================================================== 14:03:48 (1777053828) [10474.857981] LustreError: 257428:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97ee87d59000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [10474.895654] Lustre: Unmounted lustre-client [10476.814834] LustreError: 257442:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97ee89f26000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [10476.831752] LustreError: 257442:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [10476.873113] Lustre: Unmounted lustre-client [10530.276536] Lustre: Mounted lustre-client [10532.403514] Lustre: Mounted lustre-client [10534.624080] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10633.241658] Lustre: DEBUG MARKER: == sanityn test 77ki: Add rule with unsupported TBF type should fail for generic TBF ========================================================== 14:06:28 (1777053988) [10646.883480] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 14:06:42 (1777054002) [10654.557893] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 14:06:49 (1777054009) [10709.170608] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 14:07:44 (1777054064) [10781.100836] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 14:08:56 (1777054136) [10788.537593] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 14:09:04 (1777054144) [10864.383648] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 14:10:19 (1777054219) [10887.929567] Lustre: DEBUG MARKER: == sanityn test 77r: Change type of tbf policy at run time ========================================================== 14:10:43 (1777054243) [10938.364081] Lustre: DEBUG MARKER: == sanityn test 77s: Check TBF LRU shrinker ============== 14:11:34 (1777054294) [10964.015288] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 14:11:59 (1777054319) [10967.521236] Lustre: lustre-OST0000-osc-ffff97eebb6f7000: disconnect after 21s idle [10967.531414] Lustre: Skipped 16 previous similar messages [10969.483505] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 14:12:05 (1777054325) [10984.195581] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 14:12:19 (1777054339) [10985.006392] Lustre: DEBUG MARKER: SKIP: sanityn test_80a needs >= 2 MDTs [10986.063383] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 14:12:21 (1777054341) [10987.164326] Lustre: DEBUG MARKER: SKIP: sanityn test_80b needs >= 2 MDTs [10988.451228] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 14:12:23 (1777054343) [10989.550154] Lustre: DEBUG MARKER: SKIP: sanityn test_81a needs >= 2 MDTs [10990.733159] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 14:12:26 (1777054346) [10991.686693] Lustre: DEBUG MARKER: SKIP: sanityn test_81b We need at least 2 MDTs for this test [10992.786348] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 14:12:28 (1777054348) [10993.733372] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [10994.787154] Lustre: DEBUG MARKER: == sanityn test 81d: parallel rename file cross-dir on same MDT ========================================================== 14:12:30 (1777054350) [11058.619224] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 14:13:34 (1777054414) [11062.782466] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 14:13:38 (1777054418) [11063.897500] Lustre: DEBUG MARKER: SKIP: sanityn test_83 needs >= 2 MDTs [11065.022257] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 14:13:40 (1777054420) [11074.892318] Lustre: DEBUG MARKER: == sanityn test 85: Lustre API root cache race =========== 14:13:50 (1777054430) [11080.327456] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 14:13:56 (1777054436) [11081.197860] Lustre: DEBUG MARKER: SKIP: sanityn test_90 needs >= 2 MDTs [11082.354267] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 14:13:58 (1777054438) [11083.330542] Lustre: DEBUG MARKER: SKIP: sanityn test_91 needs >= 2 MDTs [11084.576122] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 14:14:00 (1777054440) [11085.538962] Lustre: DEBUG MARKER: SKIP: sanityn test_92 needs >= 2 MDTs [11086.554919] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 14:14:02 (1777054442) [11098.958120] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 14:14:14 (1777054454) [11099.137291] Lustre: DEBUG MARKER: write [11099.179088] LustreError: 270245:0:(ldlm_request.c:1525:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 sleeping for 5000ms [11101.189662] Lustre: DEBUG MARKER: kill 287857 [11101.196251] LustreError: 287857:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 sleeping for 6000ms [11104.184223] LustreError: 270245:0:(ldlm_request.c:1525:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 awake [11107.240559] LustreError: 287857:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 awake [11111.554138] Lustre: DEBUG MARKER: == sanityn test 95a: Check readpage() on a page that was removed from page cache ========================================================== 14:14:27 (1777054467) [11113.873125] LustreError: 288463:0:(rw.c:1867:ll_readpage()) cfs_fail_timeout id 1422 sleeping for 10000ms [11123.968174] LustreError: 288463:0:(rw.c:1867:ll_readpage()) cfs_fail_timeout id 1422 awake [11128.365388] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 14:14:44 (1777054484) [11128.552082] LustreError: 289042:0:(rw.c:2115:ll_readpage()) cfs_fail_timeout id 1424 sleeping for 5000ms [11130.640213] LustreError: 289042:0:(rw.c:2115:ll_readpage()) cfs_fail_timeout interrupted [11138.263154] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 14:14:54 (1777054494) [11139.203659] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [11140.348142] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 14:14:56 (1777054496) [11145.140845] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 14:15:00 (1777054500) [11149.592106] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 14:15:05 (1777054505) [11154.449039] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 14:15:10 (1777054510) [11159.166779] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 14:15:14 (1777054514) [11163.466895] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 14:15:19 (1777054519) [11167.919335] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 14:15:23 (1777054523) [11173.262634] Lustre: DEBUG MARKER: SKIP: sanityn test_102 skipping ALWAYS excluded test 102 [11174.246296] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 14:15:30 (1777054530) [11175.619280] Lustre: *** cfs_fail_loc=415, val=0*** [11184.620514] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 14:15:40 (1777054540) [11185.726663] Lustre: DEBUG MARKER: SKIP: sanityn test_104 ldiskfs only test [11186.965456] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 14:15:42 (1777054542) [11187.278078] LustreError: 260055:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 sleeping for 5000ms [11187.289488] LustreError: 260055:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 3 previous similar messages [11192.296115] LustreError: 260055:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [11202.496119] LustreError: 260055:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [11202.505079] LustreError: 260055:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 5 previous similar messages [11211.598082] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 14:16:07 (1777054567) [11212.437355] Lustre: DEBUG MARKER: SKIP: sanityn test_106a Test only for ldiskfs and statx() supported [11213.289930] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 14:16:09 (1777054569) [11217.180999] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 14:16:13 (1777054573) [11220.909292] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 14:16:16 (1777054576) [11226.752656] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 14:16:22 (1777054582) [11236.862371] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 14:16:32 (1777054592) [11237.264686] LustreError: 287218:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 sleeping for 4000ms [11237.273275] LustreError: 287218:0:(osc_request.c:2989:osc_build_rpc()) Skipped 5 previous similar messages [11241.336103] LustreError: 287218:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 awake [11241.345833] LustreError: 287218:0:(osc_request.c:2989:osc_build_rpc()) Skipped 2 previous similar messages [11245.107039] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 14:16:40 (1777054600) [11246.471664] LustreError: 298989:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97eebb6f7000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [11246.480101] LustreError: 298989:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [11246.517207] Lustre: Unmounted lustre-client [11247.127279] LustreError: 299009:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97ee836cc000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [11247.139187] LustreError: 299009:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [11247.172358] Lustre: Unmounted lustre-client [11248.027636] Lustre: DEBUG MARKER: Iteration 0 [11248.251325] LustreError: 299169:0:(llite_lib.c:1368:ll_fill_super()) cfs_race id 1417 sleeping [11248.251389] LustreError: 299170:0:(llite_lib.c:1368:ll_fill_super()) cfs_fail_race id 1417 waking [11248.265435] LustreError: 299169:0:(llite_lib.c:1368:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4993 [11248.340047] Lustre: Mounted lustre-client [11249.286462] LustreError: 299264:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97ee83f3c000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [11249.300722] LustreError: 299264:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [11249.383146] Lustre: Unmounted lustre-client [11249.389553] Lustre: Skipped 1 previous similar message [11251.275416] Key type lgssc unregistered [11251.449277] LNet: 299509:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11251.455191] LNetError: 299509:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [11251.470178] LNet: Removed LNI 192.168.201.59@tcp [11251.996170] Key type .llcrypt unregistered [11251.998697] Key type ._llcrypt unregistered [11252.616586] Key type ._llcrypt registered [11252.620594] Key type .llcrypt registered [11253.079671] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11253.090194] alg: No test for adler32 (adler32-zlib) [11254.291032] Lustre: Lustre: Build Version: 2.17.52_54_g344a3c0 [11254.729967] LNet: Added LNI 192.168.201.59@tcp [8/256/0/180] [11256.400209] Key type lgssc registered [11257.182112] Lustre: Echo OBD driver; http://www.lustre.org/ [11264.896597] Lustre: DEBUG MARKER: Iteration 1 [11265.108991] LustreError: 300330:0:(llite_lib.c:1368:ll_fill_super()) cfs_race id 1417 sleeping [11265.109068] LustreError: 300331:0:(llite_lib.c:1368:ll_fill_super()) cfs_fail_race id 1417 waking [11265.123386] LustreError: 300330:0:(llite_lib.c:1368:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4993 [11266.217208] Lustre: Mounted lustre-client [11267.156921] LustreError: 300425:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97ee87c70800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [11267.172143] LustreError: 300425:0:(lov_obd.c:792:lov_cleanup()) Skipped 2 previous similar messages [11267.191949] Lustre: Unmounted lustre-client [11268.993639] Key type lgssc unregistered [11269.161776] LNet: 300667:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11269.168654] LNetError: 300667:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [11269.182289] LNet: Removed LNI 192.168.201.59@tcp [11269.582152] Key type .llcrypt unregistered [11269.587221] Key type ._llcrypt unregistered [11270.075501] Key type ._llcrypt registered [11270.080511] Key type .llcrypt registered [11270.420057] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11270.431268] alg: No test for adler32 (adler32-zlib) [11271.377116] Lustre: Lustre: Build Version: 2.17.52_54_g344a3c0 [11271.566069] LNet: Added LNI 192.168.201.59@tcp [8/256/0/180] [11273.192155] Key type lgssc registered [11273.876143] Lustre: Echo OBD driver; http://www.lustre.org/ [11281.230077] Lustre: Mounted lustre-client [11285.485663] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 14:17:21 (1777054641) [11340.768181] Lustre: 301988:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1777054642/real 1777054642] req@ffff97eead992a00 x1863376833618688/t0(0) o36->lustre-MDT0000-mdc-ffff97ee886ea000@192.168.201.159@tcp:12/10 lens 496/440 e 0 to 1 dl 1777054697 ref 2 fl Rpc:XQr/200/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [11340.798376] Lustre: lustre-MDT0000-mdc-ffff97ee886ea000: Connection to lustre-MDT0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [11340.826421] Lustre: lustre-MDT0000-mdc-ffff97ee886ea000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [11396.064550] Lustre: 301988:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1777054697/real 1777054697] req@ffff97eead992a00 x1863376833618688/t0(0) o36->lustre-MDT0000-mdc-ffff97ee886ea000@192.168.201.159@tcp:12/10 lens 496/440 e 0 to 1 dl 1777054752 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [11396.115412] Lustre: lustre-MDT0000-mdc-ffff97ee886ea000: Connection to lustre-MDT0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [11396.175720] Lustre: lustre-MDT0000-mdc-ffff97ee886ea000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [11451.360283] Lustre: 301988:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1777054752/real 1777054752] req@ffff97eead992a00 x1863376833618688/t0(0) o36->lustre-MDT0000-mdc-ffff97ee886ea000@192.168.201.159@tcp:12/10 lens 496/440 e 0 to 1 dl 1777054807 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [11451.403708] Lustre: lustre-MDT0000-mdc-ffff97ee886ea000: Connection to lustre-MDT0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [11451.443075] Lustre: lustre-MDT0000-mdc-ffff97ee886ea000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [11452.421399] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 14:20:08 (1777054808) [11453.786252] Lustre: DEBUG MARKER: SKIP: sanityn test_111 needs >= 2 MDTs [11455.049073] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 14:20:10 (1777054810) [11456.211286] Lustre: DEBUG MARKER: SKIP: sanityn test_112 We need at least 2 MDTs for this test [11457.424137] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 14:20:12 (1777054812) [11462.328767] Lustre: DEBUG MARKER: == sanityn test 114: implicit default LMV inherit ======== 14:20:17 (1777054817) [11463.307878] Lustre: DEBUG MARKER: SKIP: sanityn test_114 We need at least 2 MDTs for this test [11464.681289] Lustre: DEBUG MARKER: == sanityn test 115: ldiskfs doesn't check direntry for uniqueness ========================================================== 14:20:20 (1777054820) [11465.788645] Lustre: DEBUG MARKER: SKIP: sanityn test_115 ldiskfs only test [11466.923135] Lustre: DEBUG MARKER: == sanityn test 116: DNE: Set default LMV layout from a remote client ========================================================== 14:20:22 (1777054822) [11468.037115] Lustre: DEBUG MARKER: SKIP: sanityn test_116 needs >= 2 MDTs [11469.145393] Lustre: DEBUG MARKER: == sanityn test 121: trunc append race =================== 14:20:24 (1777054824) [11469.296044] LustreError: 304657:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 sleeping for 2000ms [11471.384250] LustreError: 304657:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 awake [11476.090336] Lustre: DEBUG MARKER: == sanityn test 200: service remains healthy while able to process request ========================================================== 14:20:31 (1777054831) [11496.416313] Lustre: 300861:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1777054836/real 1777054836] req@ffff97eeb4abb480 x1863376833663232/t0(0) o4->lustre-OST0000-osc-ffff97ee886ea000@192.168.201.159@tcp:6/4 lens 4584/448 e 0 to 1 dl 1777054852 ref 2 fl Rpc:XQr/600/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [11496.416378] Lustre: lustre-OST0000-osc-ffff97ee886ea000: Connection to lustre-OST0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [11496.442705] Lustre: 300861:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [11496.488237] Lustre: lustre-OST0000-osc-ffff97ee886ea000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [11512.800523] Lustre: 300861:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1777054853/real 1777054853] req@ffff97eeb4abb480 x1863376833663232/t0(0) o4->lustre-OST0000-osc-ffff97ee886ea000@192.168.201.159@tcp:6/4 lens 4584/448 e 0 to 1 dl 1777054869 ref 2 fl Rpc:XQr/602/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [11512.831711] Lustre: 300861:0:(client.c:2479:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [11512.839789] Lustre: lustre-OST0000-osc-ffff97ee886ea000: Connection to lustre-OST0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [11512.871356] Lustre: lustre-OST0000-osc-ffff97ee886ea000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [11528.992188] Lustre: 300860:0:(client.c:2479:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1777054869/real 1777054869] req@ffff97eeb4abaa00 x1863376833662720/t0(0) o4->lustre-OST0000-osc-ffff97ee886ea000@192.168.201.159@tcp:6/4 lens 4584/448 e 0 to 1 dl 1777054885 ref 2 fl Rpc:XQr/602/ffffffff rc -11/-1 job:'dd.0' uid:0 gid:0 projid:0 [11529.020252] Lustre: lustre-OST0000-osc-ffff97ee886ea000: Connection to lustre-OST0000 (at 192.168.201.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [11529.049972] Lustre: lustre-OST0000-osc-ffff97ee886ea000: Connection restored to 192.168.201.159@tcp (at 192.168.201.159@tcp) [11546.657286] Lustre: DEBUG MARKER: oleg159-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff97ee82c1f800.ost_server_uuid 50 [11547.648950] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff97ee82c1f800.ost_server_uuid in IDLE state after 0 sec [11548.811837] Lustre: DEBUG MARKER: cleanup: ====================================================== [11550.108247] Lustre: DEBUG MARKER: == sanityn test complete, duration 10724 sec ============= 14:21:45 (1777054905) [11551.201469] Lustre: DEBUG MARKER: === sanityn: start cleanup 14:21:46 (1777054906) === [11659.325289] LustreError: 306658:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97ee82c1f800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [11659.356103] Lustre: Unmounted lustre-client [11661.278740] Lustre: DEBUG MARKER: === sanityn: finish cleanup 14:23:37 (1777055017) === [11661.814904] LustreError: 306959:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff97ee886ea000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [11661.825391] LustreError: 306959:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [11661.862508] Lustre: Unmounted lustre-client [11692.807586] Key type lgssc unregistered [11692.966698] LNet: 307440:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11692.975294] LNetError: 307440:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [11692.991612] LNet: Removed LNI 192.168.201.59@tcp [11693.413714] Key type .llcrypt unregistered [11693.417576] Key type ._llcrypt unregistered