[ 0.000000] Linux version 5.14.0rocky95-debug (green@maintenance) (gcc (GCC) 11.5.0 20240719 (Red Hat 11.5.0-2), GNU ld version 2.35.2-54.el9) #3 SMP PREEMPT_DYNAMIC Sun Jan 19 16:53:39 EST 2025 [ 0.000000] The list of certified hardware and cloud instances for Red Hat Enterprise Linux 9 can be viewed at the Red Hat Ecosystem Catalog, https://catalog.redhat.com. [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky9.5: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] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] APIC: Static calls initialized [ 0.000000] SMBIOS 3.0.0 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000008] kvm-clock: using sched offset of 819764328 cycles [ 0.000017] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000033] tsc: Detected 2399.998 MHz processor [ 0.000965] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.001017] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs [ 0.001028] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.001089] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.007779] found SMP MP-table at [mem 0x000f53f0-0x000f53ff] [ 0.065302] RAMDISK: [mem 0xb93f6000-0xbffbffff] [ 0.065356] ACPI: Early table checksum verification disabled [ 0.065373] ACPI: RSDP 0x00000000000F5200 000014 (v00 BOCHS ) [ 0.065391] ACPI: RSDT 0x00000000BFFE1D87 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.065411] ACPI: FACP 0x00000000BFFE1C23 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.065431] ACPI: DSDT 0x00000000BFFE0040 001BE3 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.065443] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.065455] ACPI: APIC 0x00000000BFFE1C97 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.065467] ACPI: HPET 0x00000000BFFE1D27 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.065478] ACPI: WAET 0x00000000BFFE1D5F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.065488] ACPI: Reserving FACP table memory at [mem 0xbffe1c23-0xbffe1c96] [ 0.065493] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1c22] [ 0.065497] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.065500] ACPI: Reserving APIC table memory at [mem 0xbffe1c97-0xbffe1d26] [ 0.065504] ACPI: Reserving HPET table memory at [mem 0xbffe1d27-0xbffe1d5e] [ 0.065508] ACPI: Reserving WAET table memory at [mem 0xbffe1d5f-0xbffe1d86] [ 0.066146] No NUMA configuration found [ 0.066154] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.066188] NODE_DATA(0) allocated [mem 0x1465a7000-0x1465d2fff] [ 0.066776] Reserving 256MB of memory at 2704MB for crashkernel (System RAM: 4205MB) [ 0.096144] Zone ranges: [ 0.096156] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.096167] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.096172] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.096177] Device empty [ 0.096181] Movable zone start for each node [ 0.096186] Early memory node ranges [ 0.096188] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.096193] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.096198] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.096204] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.096238] On node 0, zone DMA: 1 pages in unavailable ranges [ 0.096568] On node 0, zone DMA: 97 pages in unavailable ranges [ 0.155589] On node 0, zone Normal: 50 pages in unavailable ranges [ 0.157951] On node 0, zone Normal: 4608 pages in unavailable ranges [ 0.403886] kasan: KernelAddressSanitizer initialized [ 0.404776] ACPI: PM-Timer IO Port: 0x608 [ 0.404815] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.404919] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.404933] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.404942] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.404947] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.404952] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.404957] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.404972] ACPI: Using ACPI (MADT) for SMP configuration information [ 0.404976] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.404993] TSC deadline timer available [ 0.404997] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.405091] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write() [ 0.405131] kvm-guest: KVM setup pv remote TLB flush [ 0.405138] kvm-guest: setup PV sched yield [ 0.405205] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.405215] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.405219] PM: hibernation: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.405223] PM: hibernation: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.405231] PM: hibernation: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.405235] PM: hibernation: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.405240] PM: hibernation: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.405244] PM: hibernation: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.405247] PM: hibernation: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.405260] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.405265] Booting paravirtualized kernel on KVM [ 0.405277] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.405290] Warning: Deprecated Hardware is detected: x86_64-v2:GenuineIntel:Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz will not be maintained in a future major release and may be disabled [ 0.430898] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.440342] percpu: Embedded 531 pages/cpu s2138112 r8192 d28672 u4194304 [ 0.440545] kvm-guest: PV spinlocks enabled [ 0.440558] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.440588] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky9.5: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.440742] Booted with the nomodeset parameter. Only the system framebuffer will be available [ 0.440904] audit: disabled (until reboot) [ 0.440918] Unknown kernel command line parameters "ipmtu=9000 ip=dhcp", will be passed to user space. [ 0.441001] random: crng init done [ 0.444496] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) [ 0.446351] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) [ 0.446827] Fallback order for Node 0: 0 [ 0.446845] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.446850] Policy zone: Normal [ 0.446890] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.446895] stackdepot: allocating hash table via alloc_large_system_hash [ 0.446905] stackdepot hash table entries: 1048576 (order: 12, 16777216 bytes, linear) [ 0.453887] software IO TLB: area num 4. [ 1.369514] Memory: 2722508K/4306352K available (43008K kernel code, 14200K rwdata, 17804K rodata, 5284K init, 25448K bss, 1220588K reserved, 0K cma-reserved) [ 1.369536] ********************************************************** [ 1.369540] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 1.369543] ** ** [ 1.369546] ** This system shows unhashed kernel memory addresses ** [ 1.369548] ** via the console, logs, and other interfaces. This ** [ 1.369551] ** might reduce the security of your system. ** [ 1.369554] ** ** [ 1.369557] ** If you see this message and you are not debugging ** [ 1.369559] ** the kernel, report this immediately to your system ** [ 1.369562] ** administrator! ** [ 1.369565] ** ** [ 1.369567] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 1.369570] ********************************************************** [ 1.372540] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 1.372556] kmemleak: Kernel memory leak detector disabled [ 1.379148] ftrace: allocating 51191 entries in 200 pages [ 1.397978] ftrace: allocated 200 pages with 3 groups [ 1.405450] Dynamic Preempt: voluntary [ 1.408543] rcu: Preemptible hierarchical RCU implementation. [ 1.408553] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 1.408561] rcu: RCU callback double-/use-after-free debug is enabled. [ 1.408565] Trampoline variant of Tasks RCU enabled. [ 1.408568] Rude variant of Tasks RCU enabled. [ 1.408570] Tracing variant of Tasks RCU enabled. [ 1.408574] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 1.408578] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 1.479891] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 1.481284] rcu: srcu_init: Setting srcu_struct sizes based on contention. [ 1.482188] Console: colour *CGA 80x25 [ 1.482358] printk: console [ttyS1] enabled [ 1.763688] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 1.766422] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 1.767887] ... MAX_LOCK_DEPTH: 48 [ 1.769366] ... MAX_LOCKDEP_KEYS: 8192 [ 1.770906] ... CLASSHASH_SIZE: 4096 [ 1.772426] ... MAX_LOCKDEP_ENTRIES: 65536 [ 1.774008] ... MAX_LOCKDEP_CHAINS: 262144 [ 1.775615] ... CHAINHASH_SIZE: 131072 [ 1.776855] memory used by lock dependency info: 6889 kB [ 1.778071] per task-struct memory footprint: 2688 bytes [ 1.779945] ACPI: Core revision 20230331 [ 1.782801] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 1.786476] APIC: Switch to symmetric I/O mode setup [ 1.790021] x2apic enabled [ 1.791500] APIC: Switched APIC routing to: physical x2apic [ 1.792917] kvm-guest: APIC: send_IPI_mask() replaced with kvm_send_ipi_mask() [ 1.794802] kvm-guest: APIC: send_IPI_mask_allbutself() replaced with kvm_send_ipi_mask_allbutself() [ 1.796882] kvm-guest: setup PV IPIs [ 1.800244] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 1.802305] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 1.805567] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 1.807602] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 1.809657] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 1.810560] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 1.811591] Spectre V2 : User space: Vulnerable [ 1.812557] Speculative Store Bypass: Vulnerable [ 1.813619] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 1.814564] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 1.815561] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 1.816564] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 1.817561] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 1.821607] debug: unmapping init [mem 0xffffffffb911b000-0xffffffffb9124fff] [ 1.822603] pid_max: default: 32768 minimum: 301 [ 1.824896] LSM: initializing lsm=lockdown,capability,yama,integrity,selinux,bpf [ 1.826751] Yama: becoming mindful. [ 1.827753] SELinux: Initializing. [ 1.829204] LSM support for eBPF active [ 1.831235] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 1.831618] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 1.840393] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 1.844731] RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. [ 1.846104] RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. [ 1.847135] RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1. [ 1.848176] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 1.848602] ... version: 2 [ 1.849565] ... bit width: 48 [ 1.850563] ... generic registers: 4 [ 1.851567] ... value mask: 0000ffffffffffff [ 1.852570] ... max period: 00007fffffffffff [ 1.853569] ... fixed-purpose events: 3 [ 1.854565] ... event mask: 000000070000000f [ 1.856491] signal: max sigframe size: 1776 [ 1.857611] rcu: Hierarchical SRCU implementation. [ 1.857621] rcu: Max phase no-delay instances is 400. [ 1.872854] smp: Bringing up secondary CPUs ... [ 1.877161] smpboot: x86: Booting SMP configuration: [ 1.877188] .... node #0, CPUs: #2 [ 1.883866] #1 #3 [ 1.892991] smp: Brought up 1 node, 4 CPUs [ 1.893021] smpboot: Max logical packages: 1 [ 1.893031] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 1.967747] node 0 deferred pages initialised in 67ms [ 1.968021] pgdatinit0 (40) used greatest stack depth: 29784 bytes left [ 1.975561] devtmpfs: initialized [ 1.977850] x86/mm: Memory block size: 128MB [ 2.034902] DMA-API: preallocated 65536 debug entries [ 2.034964] DMA-API: debugging enabled by kernel config [ 2.034979] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 2.035022] futex hash table entries: 1024 (order: 5, 131072 bytes, linear) [ 2.036663] prandom: seed boundary self test passed [ 2.038174] prandom: 100 self tests passed [ 2.038201] pinctrl core: initialized pinctrl subsystem [ 2.039941] [ 2.039949] ************************************************************* [ 2.039953] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 2.039957] ** ** [ 2.039960] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 2.039963] ** ** [ 2.039967] ** This means that this kernel is built to expose internal ** [ 2.039970] ** IOMMU data structures, which may compromise security on ** [ 2.039974] ** your system. ** [ 2.039977] ** ** [ 2.039980] ** If you see this message and you are not debugging the ** [ 2.039984] ** kernel, report this immediately to your vendor! ** [ 2.039987] ** ** [ 2.039990] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 2.039993] ************************************************************* [ 2.042563] PM: RTC time: 07:53:58, date: 2025-04-01 [ 2.049158] NET: Registered PF_NETLINK/PF_ROUTE protocol family [ 2.058542] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 2.058542] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 2.058542] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 2.065027] thermal_sys: Registered thermal governor 'fair_share' [ 2.065041] thermal_sys: Registered thermal governor 'step_wise' [ 2.065049] thermal_sys: Registered thermal governor 'user_space' [ 2.068590] cpuidle: using governor menu [ 2.078906] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 2.082785] PCI: Using configuration type 1 for base access [ 2.083010] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 2.211632] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible. [ 2.216042] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages [ 2.216042] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page [ 2.216042] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages [ 2.216042] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page [ 2.242652] cryptd: max_cpu_qlen set to 1000 [ 2.253113] ACPI: Added _OSI(Module Device) [ 2.253568] ACPI: Added _OSI(Processor Device) [ 2.253568] ACPI: Added _OSI(3.0 _SCP Extensions) [ 2.253568] ACPI: Added _OSI(Processor Aggregator Device) [ 2.253568] ACPI: Added _OSI(Linux-Dell-Video) [ 2.253568] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio) [ 2.253568] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics) [ 2.342259] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 2.384079] ACPI: _OSC evaluation for CPUs failed, trying _PDC [ 2.395107] ACPI: Interpreter enabled [ 2.395605] ACPI: PM: (supports S0 S3 S4 S5) [ 2.395626] ACPI: Using IOAPIC for interrupt routing [ 2.398323] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 2.398347] PCI: Using E820 reservations for host bridge windows [ 2.404339] ACPI: Enabled 2 GPEs in block 00 to 0F [ 2.591248] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 2.591380] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI EDR HPX-Type3] [ 2.591392] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 2.592085] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended configuration space under this bridge [ 2.611844] acpiphp: Slot [2] registered [ 2.612559] acpiphp: Slot [5] registered [ 2.613143] acpiphp: Slot [6] registered [ 2.614331] acpiphp: Slot [7] registered [ 2.615006] acpiphp: Slot [8] registered [ 2.616418] acpiphp: Slot [9] registered [ 2.617107] acpiphp: Slot [10] registered [ 2.617814] acpiphp: Slot [3] registered [ 2.618416] acpiphp: Slot [4] registered [ 2.619095] acpiphp: Slot [11] registered [ 2.619706] acpiphp: Slot [12] registered [ 2.620381] acpiphp: Slot [13] registered [ 2.620998] acpiphp: Slot [14] registered [ 2.621708] acpiphp: Slot [15] registered [ 2.622358] acpiphp: Slot [16] registered [ 2.623081] acpiphp: Slot [17] registered [ 2.623758] acpiphp: Slot [18] registered [ 2.624630] acpiphp: Slot [19] registered [ 2.625330] acpiphp: Slot [20] registered [ 2.625972] acpiphp: Slot [21] registered [ 2.626584] acpiphp: Slot [22] registered [ 2.627223] acpiphp: Slot [23] registered [ 2.627884] acpiphp: Slot [24] registered [ 2.628542] acpiphp: Slot [25] registered [ 2.629149] acpiphp: Slot [26] registered [ 2.629864] acpiphp: Slot [27] registered [ 2.630444] acpiphp: Slot [28] registered [ 2.631109] acpiphp: Slot [29] registered [ 2.631731] acpiphp: Slot [30] registered [ 2.632360] acpiphp: Slot [31] registered [ 2.632690] PCI host bridge to bus 0000:00 [ 2.632719] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 2.632745] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 2.632770] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 2.632794] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 2.632817] pci_bus 0000:00: root bus resource [mem 0x380000000000-0x38007fffffff window] [ 2.632850] pci_bus 0000:00: root bus resource [bus 00-ff] [ 2.633534] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint [ 2.641154] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint [ 2.648437] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint [ 2.654241] pci 0000:00:01.1: BAR 4 [io 0xc320-0xc32f] [ 2.656441] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk [ 2.656461] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk [ 2.656467] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk [ 2.656472] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk [ 2.661578] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint [ 2.665365] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 2.665497] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 2.672186] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint [ 2.673487] pci 0000:00:02.0: BAR 0 [io 0xc300-0xc31f] [ 2.680570] pci 0000:00:02.0: BAR 4 [mem 0x380000000000-0x380000003fff 64bit pref] [ 2.682569] pci 0000:00:02.0: ROM [mem 0xfeb80000-0xfebbffff pref] [ 2.744983] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint [ 2.752570] pci 0000:00:05.0: BAR 0 [io 0xc000-0xc07f] [ 2.753542] pci 0000:00:05.0: BAR 1 [mem 0xfebc0000-0xfebc0fff] [ 2.753542] pci 0000:00:05.0: BAR 4 [mem 0x380000004000-0x380000007fff 64bit pref] [ 2.816813] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint [ 2.819581] pci 0000:00:06.0: BAR 0 [io 0xc080-0xc0ff] [ 2.824577] pci 0000:00:06.0: BAR 1 [mem 0xfebc1000-0xfebc1fff] [ 2.843568] pci 0000:00:06.0: BAR 4 [mem 0x380000008000-0x38000000bfff 64bit pref] [ 2.919238] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint [ 2.920542] pci 0000:00:07.0: BAR 0 [io 0xc100-0xc17f] [ 2.920542] pci 0000:00:07.0: BAR 1 [mem 0xfebc2000-0xfebc2fff] [ 2.920542] pci 0000:00:07.0: BAR 4 [mem 0x38000000c000-0x38000000ffff 64bit pref] [ 2.978542] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint [ 2.980567] pci 0000:00:08.0: BAR 0 [io 0xc180-0xc1ff] [ 2.984572] pci 0000:00:08.0: BAR 1 [mem 0xfebc3000-0xfebc3fff] [ 2.988584] pci 0000:00:08.0: BAR 4 [mem 0x380000010000-0x380000013fff 64bit pref] [ 3.059412] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint [ 3.060542] pci 0000:00:09.0: BAR 0 [io 0xc200-0xc27f] [ 3.060542] pci 0000:00:09.0: BAR 1 [mem 0xfebc4000-0xfebc4fff] [ 3.060542] pci 0000:00:09.0: BAR 4 [mem 0x380000014000-0x380000017fff 64bit pref] [ 3.124016] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint [ 3.125542] pci 0000:00:0a.0: BAR 0 [io 0xc280-0xc2ff] [ 3.125542] pci 0000:00:0a.0: BAR 1 [mem 0xfebc5000-0xfebc5fff] [ 3.125542] pci 0000:00:0a.0: BAR 4 [mem 0x380000018000-0x38000001bfff 64bit pref] [ 3.209351] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 3.216329] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 3.223321] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 3.225542] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 3.227542] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 3.245053] iommu: Default domain type: Translated [ 3.245053] iommu: DMA domain TLB invalidation policy: lazy mode [ 3.250646] SCSI subsystem initialized [ 3.251954] ACPI: bus type USB registered [ 3.252943] usbcore: registered new interface driver usbfs [ 3.253366] usbcore: registered new interface driver hub [ 3.253743] usbcore: registered new device driver usb [ 3.255410] pps_core: LinuxPPS API ver. 1 registered [ 3.255419] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 3.255579] PTP clock support registered [ 3.266162] NetLabel: Initializing [ 3.266196] NetLabel: domain hash size = 128 [ 3.266205] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 3.266781] NetLabel: unlabeled traffic allowed by default [ 3.266794] PCI: Using ACPI for IRQ routing [ 3.268372] vgaarb: loaded [ 3.270531] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 3.270565] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 3.277468] clocksource: Switched to clocksource kvm-clock [ 4.125832] VFS: Disk quotas dquot_6.6.0 [ 4.127758] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 4.129968] pnp: PnP ACPI init [ 4.158133] pnp: PnP ACPI: found 6 devices [ 4.246740] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 4.251140] NET: Registered PF_INET protocol family [ 4.252640] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear) [ 4.260582] tcp_listen_portaddr_hash hash table entries: 4096 (order: 6, 327680 bytes, linear) [ 4.264515] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) [ 4.264930] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear) [ 4.267989] TCP bind hash table entries: 65536 (order: 10, 5242880 bytes, vmalloc hugepage) [ 4.274524] TCP: Hash tables configured (established 65536 bind 65536) [ 4.277570] MPTCP token hash table entries: 8192 (order: 7, 786432 bytes, linear) [ 4.278803] UDP hash table entries: 4096 (order: 7, 786432 bytes, linear) [ 4.280566] UDP-Lite hash table entries: 4096 (order: 7, 786432 bytes, linear) [ 4.282712] NET: Registered PF_UNIX/PF_LOCAL protocol family [ 4.290605] RPC: Registered named UNIX socket transport module. [ 4.290620] RPC: Registered udp transport module. [ 4.290624] RPC: Registered tcp transport module. [ 4.290628] RPC: Registered tcp-with-tls transport module. [ 4.290633] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 4.290650] NET: Registered PF_XDP protocol family [ 4.290692] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 4.290707] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 4.290714] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 4.290721] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 4.290728] pci_bus 0000:00: resource 8 [mem 0x380000000000-0x38007fffffff window] [ 4.292612] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 4.292719] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 4.293364] PCI: CLS 0 bytes, default 64 [ 4.293542] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 4.293548] software IO TLB: mapped [mem 0x00000000a5000000-0x00000000a9000000] (64MB) [ 4.293734] ACPI: bus type thunderbolt registered [ 4.295017] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 4.295054] Trying to unpack rootfs image as initramfs... [ 4.371805] Initialise system trusted keyrings [ 4.372303] Key type blacklist registered [ 4.373135] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 4.410109] zbud: loaded [ 4.416594] NFS: Registering the id_resolver key type [ 4.416742] Key type id_resolver registered [ 4.416750] Key type id_legacy registered [ 4.416908] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 4.416933] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... [ 4.431711] integrity: Platform Keyring initialized [ 4.431873] integrity: Machine keyring initialized [ 4.445152] NET: Registered PF_ALG protocol family [ 4.445371] xor: automatically using best checksumming function avx [ 4.445383] Key type asymmetric registered [ 4.445405] Asymmetric key parser 'x509' registered [ 4.445411] Running certificate verification selftests [ 4.454116] cryptomgr_test (69) used greatest stack depth: 28672 bytes left [ 4.455317] cryptomgr_probe (68) used greatest stack depth: 28600 bytes left [ 4.457479] Loaded X.509 cert 'Certificate verification self-testing key: f58703bb33ce1b73ee02eccdee5b8817518fe3db' [ 4.465486] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246) [ 4.466303] io scheduler mq-deadline registered [ 4.466313] io scheduler kyber registered [ 4.466525] io scheduler bfq registered [ 4.474578] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 4.478508] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 4.482231] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 4.486569] ACPI: button: Power Button [PWRF] [ 8.886734] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 11.293523] debug: unmapping init [mem 0xffff8880b93f6000-0xffff8880bffbffff] [ 13.359956] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 23.166172] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 27.994184] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 36.786832] hrtimer: interrupt took 19563024 ns [ 47.003104] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 47.008675] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 47.015422] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 47.156322] Non-volatile memory driver v1.3 [ 47.878359] virtio_blk virtio1: 4/0/0 default/read/poll queues [ 47.934877] virtio_blk virtio1: [vda] 131792 512-byte logical blocks (67.5 MB/64.4 MiB) [ 47.972646] virtio_blk virtio2: 4/0/0 default/read/poll queues [ 48.019921] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 48.090766] virtio_blk virtio3: 4/0/0 default/read/poll queues [ 48.125987] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 48.149129] virtio_blk virtio4: 4/0/0 default/read/poll queues [ 48.200190] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 48.428111] virtio_blk virtio5: 4/0/0 default/read/poll queues [ 48.477010] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 48.541669] virtio_blk virtio6: 4/0/0 default/read/poll queues [ 48.566566] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 48.596194] rdac: device handler registered [ 48.601834] hp_sw: device handler registered [ 48.604107] emc: device handler registered [ 48.605194] alua: device handler registered [ 48.751737] usbcore: registered new interface driver usbserial_generic [ 48.752083] usbserial: USB Serial support registered for generic [ 48.759021] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 48.769065] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 48.769209] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 48.778755] mousedev: PS/2 mouse device common for all mice [ 48.784148] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 48.791149] rtc_cmos 00:05: RTC can wake from S4 [ 48.812825] rtc_cmos 00:05: registered as rtc0 [ 48.813054] rtc_cmos 00:05: setting system clock to 2025-04-01T07:54:46 UTC (1743494086) [ 48.813914] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 48.814217] intel_pstate: CPU model not supported [ 48.822376] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 48.852453] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 48.856583] hid: raw HID events driver (C) Jiri Kosina [ 48.868100] usbcore: registered new interface driver usbhid [ 48.868116] usbhid: USB HID core driver [ 48.868530] drop_monitor: Initializing network drop monitor service [ 49.012322] Initializing XFRM netlink socket [ 49.021860] NET: Registered PF_INET6 protocol family [ 49.368479] modprobe (101) used greatest stack depth: 26672 bytes left [ 50.055975] modprobe (106) used greatest stack depth: 26664 bytes left [ 50.079711] Segment Routing with IPv6 [ 50.080071] NET: Registered PF_PACKET protocol family [ 50.103747] Key type dns_resolver registered [ 50.103810] mpls_gso: MPLS GSO support [ 50.125657] IPI shorthand broadcast: enabled [ 50.127685] AVX version of gcm_enc/dec engaged. [ 50.137393] AES CTR mode by8 optimization enabled [ 50.140160] sched_clock: Marking stable (49823017464, 316235471)->(50542369806, -403116871) [ 50.201890] registered taskstats version 1 [ 50.217842] Loading compiled-in X.509 certificates [ 50.242630] Loaded X.509 cert 'Build time autogenerated kernel key: e7dd487b25da3070ab21d0f388d69a833b127865' [ 50.556910] debug_vm_pgtable: [debug_vm_pgtable ]: Validating architecture page table helpers [ 50.646192] page_owner is disabled [ 50.656706] Key type big_key registered [ 50.757390] modprobe (113) used greatest stack depth: 26472 bytes left [ 50.894995] modprobe (114) used greatest stack depth: 26384 bytes left [ 50.916399] Key type encrypted registered [ 50.925809] ima: No TPM chip found, activating TPM-bypass! [ 50.925990] Loading compiled-in module X.509 certificates [ 50.936593] Loaded X.509 cert 'Build time autogenerated kernel key: e7dd487b25da3070ab21d0f388d69a833b127865' [ 50.938178] ima: Allocated hash algorithm: sha256 [ 50.938478] ima: No architecture policies found [ 50.940956] evm: Initialising EVM extended attributes: [ 50.940967] evm: security.selinux [ 50.940973] evm: security.SMACK64 (disabled) [ 50.940977] evm: security.SMACK64EXEC (disabled) [ 50.940980] evm: security.SMACK64TRANSMUTE (disabled) [ 50.940984] evm: security.SMACK64MMAP (disabled) [ 50.940988] evm: security.apparmor (disabled) [ 50.940992] evm: security.ima [ 50.940995] evm: security.capability [ 50.940998] evm: HMAC attrs: 0x1 [ 56.285160] PM: Magic number: 5:142:874 [ 56.524877] clk: Disabling unused clocks [ 56.682876] debug: unmapping init [mem 0xffffffffba803000-0xffffffffba9fffff] [ 56.690922] debug: unmapping init [mem 0xffffffffb8bf2000-0xffffffffb911afff] [ 56.700481] Write protecting the kernel read-only data: 61440k [ 56.713675] debug: unmapping init [mem 0xffffffffb7563000-0xffffffffb75fffff] [ 57.025026] x86/mm: Checked W+X mappings: passed, no W+X pages found. [ 57.028526] Run /init as init process [ 58.369999] systemd[1]: systemd 252-46.el9_5.2.0.1 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK +XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified) Welcome to Rocky Linux 9.5 (Blue Onyx) dracut-057-70.git20240819.el9 (Initramfs)! [ 58.380434] systemd[1]: Detected virtualization kvm. [ 58.380500] systemd[1]: Detected architecture x86-64. [ 58.380538] systemd[1]: Running in initrd. [ 58.432469] systemd[1]: No hostname configured, using default hostname. [ 58.433741] systemd[1]: Hostname set to . [ 58.435373] systemd[1]: Initializing machine ID from random generator. [ 60.264144] systemd-debug-g (222) used greatest stack depth: 25992 bytes left [ 62.828138] systemd[1]: Queued start job for default target Initrd Default Target. [ 62.854156] 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. [ 62.894647] systemd[1]: Reached target Local Encrypted Volumes. [ 62.906143] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 62.917643] systemd[1]: Reached target Initrd /usr File System. [ OK ] Reached target Initrd /usr File System. [ 62.926901] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ OK ] Reached target Path Units. [ 62.948854] systemd[1]: Reached target Path Units. [ 62.965723] systemd[1]: Reached target Slice Units. [ OK ] Reached target Slice Units. [ OK ] Reached target Swaps. [ 62.986015] systemd[1]: Reached target Swaps. [ 62.998118] systemd[1]: Reached target Timer Units. [ OK ] Reached target Timer Units. [ 63.022461] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 63.043639] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 63.060722] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 63.073914] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 63.083679] systemd[1]: Reached target Socket Units. [ OK ] Reached target Socket Units. [ 63.239284] systemd[1]: Starting Create List of Static Device Nodes... Starting Create List of Static Device Nodes... [ 63.257524] systemd[1]: Memstrack Anylazing Service was skipped because no trigger condition checks were met. Starting Journal Service... [ 63.567411] systemd[1]: Starting Journal Service... [ 63.581463] systemd[1]: Load Kernel Modules was skipped because no trigger condition checks were met. [ 64.050161] systemd[1]: Starting Apply Kernel Variables... Starting Apply Kernel Variables... [ 64.231844] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... [ 64.508569] systemd[1]: Finished Create List of Static Device Nodes. [ OK ] Finished Create List of Static Device Nodes. [ 65.086063] systemd[1]: Finished Apply Kernel Variables. [ OK ] Finished Apply Kernel Variables. [ 65.124465] systemd[1]: Finished Setup Virtual Console. [ OK ] Finished Setup Virtual Console. [ 65.313196] systemd[1]: dracut ask for additional cmdline parameters was skipped because no trigger condition checks were met. [ 65.432784] systemd[1]: Starting dracut cmdline hook... Starting dracut cmdline hook... [ 65.571978] systemd[1]: Starting Create Static Device Nodes in /dev... Starting Create Static Device Nodes in /dev... [ OK [[ 66.948717] systemd[1]: Finished Create Static Device Nodes in /dev. 0m] Finished Create Static Device Nodes in /dev. [ 67.287121] systemd[1]: Started Journal Service. [ OK ] Started Journal Service. Starting Create Volatile Files and Directories... [ OK ] Finished Create Volatile Files and Directories. [ OK ] Finished dracut cmdline hook. Starting dracut pre-udev hook... [ 73.471118] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log. [ 73.480339] device-mapper: uevent: version 1.0.3 [ 73.513632] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com [ OK ] Finished dracut pre-udev hook. Starting Rule-based Manager for Device Events and Files... [ OK ] Started Rule-based Manager for Device Events and Files. Starting dracut pre-trigger hook... [ OK ] Finished dracut pre-trigger hook. Starting Coldplug All udev Devices... [ ***] A start job is running for Coldplug All udev Devices (18s / no limit) M [ *** ] A start job is running for Coldplug All udev Devices (19s / no limit) M [ *** ] A start job is running for Coldplug All udev Devices (19s / no limit) M [*** ] A start job is running for Coldplug All udev Devices (20s / no limit) M [** ] A start job is running for Coldplug All udev Devices (20s / no limit) M [* ] A start job is running for Coldplug All udev Devices (21s / no limit) M [** ] A start job is running for Coldplug All udev Devices (21s / no limit) M [*** ] A start job is running for Coldplug All udev Devices (22s / no limit) M [ *** ] A start job is running for Coldplug All udev Devices (22s / no limit) M [ *** ] A start job is running for Coldplug All udev Devices (23s / no limit) M [ ***] A start job is running for Coldplug All udev Devices (23s / no limit) M [ **] A start job is running for Coldplug All udev Devices (24s / no limit) M [ *] A start job is running for Coldplug All udev Devices (24s / no limit) M [ OK ] Finished Coldplug All udev Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. Starting dracut initqueue hook... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 89.927468] virtio_net virtio0 ens2: renamed from eth0 [ 98.170563] ip (573) used greatest stack depth: 24976 bytes left [ 98.332758] scsi host0: ata_piix [ 98.462392] scsi host1: ata_piix [ 98.470624] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 lpm-pol 0 [ 98.470673] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 lpm-pol 0 [ 99.082257] workqueue: delayed_vfree_work hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 102.882308] workqueue: delayed_vfree_work hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 103.999699] dracut-initqueue[657]: Error: ipv4: Address already assigned. [ 115.134160] nbd0: detected capacity change from 0 to 62914560 [ OK ] Finished dracut initqueue hook. [ OK ] Reached target Preparation for Remote File Systems. [ OK ] Reached target Remote Encrypted Volumes. [ OK ] Reached target Remote File Systems. Starting dracut pre-mount hook... [ OK ] Finished dracut pre-mount hook. Mounting /sysroot... [ 118.999925] systemd-udevd (747) used greatest stack depth: 22064 bytes left [ 120.426713] EXT4-fs (nbd0): mounted filesystem 78814501-6d48-4019-818e-1b1fdcf55d3f ro with ordered data mode. Quota mode: none. [ 120.443495] mount (762) used greatest stack depth: 21680 bytes left [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Mountpoints Configured in the Real Root... [ 121.345344] systemd-fstab-g (768) used greatest stack depth: 21088 bytes left [ OK ] Finished Mountpoints Configured in the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ 125.764641] workqueue: delayed_vfree_work hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND [ OK ] Finished dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Remote Encrypted Volumes. [ OK ] Stopped target Timer Units. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Initrd /usr File System. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Preparation for Remote File Systems. [ OK ] Stopped dracut pre-mount hook. [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Setup Virtual Console. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Path Units. [ OK ] Stopped target Slice Units. [ OK ] Stopped target Socket Units. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swaps. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped Coldplug All udev Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping Rule-based Manager for Device Events and Files... [ OK ] Finished Cleaning Up and Shutting Down Daemons. [ OK ] Stopped Rule-based Manager for Device Events and Files. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. Starting Cleanup udev Database... [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create List of Static Device Nodes. [ OK ] Finished Cleanup udev Database. [ OK ] Reached target Switch Root. Starting Switch Root... [ 130.540401] systemd-journald[263]: Received SIGTERM from PID 1 (systemd). [ 139.177319] systemd[1]: systemd 252-46.el9_5.2.0.1 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK +XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified) Welcome to Rocky Linux 9.5 (Blue Onyx)! [ 139.178870] systemd[1]: Detected virtualization kvm. [ 139.178942] systemd[1]: Detected architecture x86-64. [ 142.950130] systemd-rc-local-generator[831]: /etc/rc.d/rc.local is not marked executable, skipping. [ 143.131384] kdump-dep-gener (819) used greatest stack depth: 20736 bytes left [ OK ] Stopped Switch Root. [ 148.375225] systemd[1]: initrd-switch-root.service: Deactivated successfully. [ 148.384560] systemd[1]: Stopped Switch Root. [ OK ] Created slice Slice /system/getty. [ 148.428389] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 148.436273] systemd[1]: Created slice Slice /system/getty. [ 148.470162] systemd[1]: Created slice Slice /system/modprobe. [ OK ] Created slice Slice /system/modprobe. [ 148.514483] systemd[1]: Created slice Slice /system/serial-getty. [ OK ] Created slice Slice /system/serial-getty. [ 148.564892] systemd[1]: Created slice Slice /system/sshd-keygen. [ OK ] Created slice Slice /system/sshd-keygen. [ 148.610462] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. [ 148.637862] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 148.677720] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 148.714898] systemd[1]: proc-sys-fs-binfmt_misc.automount: Refusing to start, unit proc-sys-fs-binfmt_misc.mount to trigger not loaded. [ 148.719181] systemd[1]: Failed to set up automount Arbitrary Executable File Formats File System Automount Point. [FAILED] Failed to set up automount Arbitra…ormats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ 148.774808] systemd[1]: Reached target Local Encrypted Volumes. [ OK ] Reached target Local Encrypted Volumes. [ 148.783805] systemd[1]: Stopped target Switch Root. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ 148.799536] systemd[1]: Stopped target Initrd File Systems. [ 148.815523] systemd[1]: Stopped target Initrd Root File System. [ OK ] Stopped target Initrd Root File System. [ 148.835562] systemd[1]: Reached target Local Integrity Protected Volumes. [ OK ] Reached target Local Integrity Protected Volumes. [ 148.859339] systemd[1]: Reached target Path Units. [ OK ] Reached target Path Units. [ 148.878330] systemd[1]: Reached target rpc_pipefs.target. [ OK ] Reached target rpc_pipefs.target. [ 148.901619] systemd[1]: Reached target Slice Units. [ OK ] Reached target Slice Units. [ 148.913644] systemd[1]: Reached target Local Verity Protected Volumes. [ OK ] Reached target Local Verity Protected Volumes. [ OK ] Listening on RPCbind Server Activat[ 149.388050] systemd[1]: Listening on RPCbind Server Activation Socket. ion Socket. [ 149.408902] systemd[1]: Reached target RPC Port Mapper. [ OK ] Reached target RPC Port Mapper. [ 149.468879] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ 149.507151] systemd[1]: Listening on initctl Compatibility Named Pipe. [ OK ] Listening on initctl Compatibility Named Pipe. [ 149.550852] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 149.596124] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 149.717737] systemd[1]: Mounting Huge Pages File System... Mounting Huge Pages File System... Mounting POSIX Message Queue File System... [ 149.906794] systemd[1]: Mounting POSIX Message Queue File System... [ 149.957534] systemd[1]: Mounting Kernel Debug File System... Mounting Kernel Debug File System... Mountin[ 150.098165] systemd[1]: Mounting Kernel Trace File System... g Kernel Trace File System... [ 150.124396] systemd[1]: Kernel Module supporting RPCSEC_GSS was skipped because of an unmet condition check (ConditionPathExists=/etc/krb5.keytab). Starting Create List of Static Device Nodes... [ 150.285826] systemd[1]: Starting Create List of Static Device Nodes... [ 150.329079] systemd[1]: Load legacy module configuration was skipped because no trigger condition checks were met. [ 150.486442] systemd[1]: Starting Load Kernel Module configfs... Starting Load Kernel Module configfs... [ 150.675325] systemd[1]: Starting Load Kernel Module drm... Starting Load Kernel Module drm... [ 150.832231] systemd[1]: Starting Load Kernel Module fuse... Starting Load Kernel Module fuse... [ 150.889284] systemd[1]: Read and set NIS domainname from /etc/sysconfig/network was skipped because of an unmet condition check (ConditionPathExists=/etc/sysconfig/network). [ 150.889785] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 150.945582] systemd[1]: systemd-journald.service: Consumed 1.397s CPU time. Starting Journal Service... [ 151.347903] systemd[1]: Starting Journal Service... [ 151.486580] systemd[1]: Load Kernel Modules was skipped because no trigger condition checks were met. [ 151.491628] systemd[1]: TPM2 PCR Machine ID Measurement was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/StubPcrKernelImage-4a67b082-0a4c-41cf-b6c7-440b29bb8c4f). [ 151.572769] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ 151.628661] systemd[1]: Repartition Root Disk was skipped because no trigger condition checks were met. [ 151.931678] systemd[1]: Starting Apply Kernel Variables... Starting Apply Kernel Variables... [ 152.252072] systemd[1]: Starting Coldplug All udev Devices... Starting Coldplug All udev Devices... [ 152.551354] systemd[1]: Mounted Huge Pages File System. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Kernel Trace File System. [ 152.587701] systemd[1]: Mounted POSIX Message Queue File System. [ 152.599674] systemd[1]: Mounted Kernel Debug File System. [ 152.613023] systemd[1]: Mounted Kernel Trace File System. [ OK ] Finished Create List of Static Device Nodes. [ 152.638075] systemd[1]: Finished Create List of Static Device Nodes. [ 152.683508] systemd[1]: modprobe@configfs.service: Deactivated successfully. [ 152.693921] systemd[1]: Finished Load Kernel Module configfs. [ OK ] Finished Load Kernel Module configfs. [ 153.337140] fuse: init (API version 7.36) Mounting Kernel Configuration File System... [ 153.378754] systemd[1]: Mounting Kernel Configuration File System... [ OK ] Started Journal Service. [ 153.396965] systemd[1]: Started Journal Service. [ 153.896220] ACPI: bus type drm_connector registered [ OK ] Finished Load Kernel Module fuse. [ OK ] Finished Load Kernel Module drm.[ 154.013071] workqueue: do_free_init hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Finished Apply Kernel Variables. [ OK ] Mounted Kernel Configuration File System. Mounting FUSE Control File System... Starting Configure read-only root support... Starting Flush Journal to Persistent Storage... Starting Create Static Device Nodes in /dev... [ OK ] Mounted FUSE Control File System. [ 155.599758] systemd-journald[853]: Received client request to flush runtime journal. [ OK ] Finished Flush Journal to Persistent Storage. [ OK ] Finished Create Static Device Nodes in /dev. [ OK ] Reached target Preparation for Local File Systems. Mounting /mnt... Starting Rule-based Manager for Device Events and Files... [ OK ] Mounted /mnt. [* ] (1 of 7) A start job is running for /dev/ttyS1 (11s / no limit) M [ OK ] Started Rule-based Manager for Device Events and Files. [** ] (1 of 6) A start job is running for /dev/ttyS1 (14s / no limit) M [*** ] (1 of 6) A start job is running for /dev/ttyS1 (14s / no limit) M [ *** ] (2 of 6) A start job is running for /dev/ttyS0 (15s / no limit) M [ *** ] (2 of 6) A start job is running for /dev/ttyS0 (15s / no limit) M  Starting Load Kernel Module configfs... [ OK ] Finished Load Kernel Module configfs. [ OK ] Finished Coldplug All udev Devices. Mounting /home/green/git/lustre-release... Activating swap /dev/disk/by-label/SWAP... [ 168.343064] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 168.576877] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Reached target Swaps. [ 170.087417] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 170.268261] workqueue: do_free_init hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 170.433576] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ ***] A start job is running for Configur…only root support (23s / no limit) M [ **] A start job is running for Configur…only root support (24s / no limit) M [ *] A start job is running for Configur…only root support (24s / no limit) M [ **] A start job is running for Configur…only root support (25s / no limit) M [ ***] A start job is running for Configur…only root support (25s / no limit) M [ *** ] A start job is running for Configur…only root support (26s / no limit) M [ *** ] A start job is running for Configur…only root support (26s / no limit) [ 174.516611] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer M [*** ] A start job is running for Configur…only root support (27s / no limit) M [** ] A start job is running for Configur…only root support (27s / no limit) M [* ] A start job is running for Configur…only root support (28s / no limit) M [** ] A start job is running for Configur…only root support (28s / no limit) M [*** ] A start job is running for Configur…only root support (29s / no limit) M [ *** ] A start job is running for Configur…only root support (29s / no limit) M [ *** ] A start job is running for Configur…only root support (30s / no limit) M [ ***] A start job is running for Configur…only root support (30s / no limit) M [ **] A start job is running for Configur…only root support (31s / no limit) M [ *] A start job is running for Configur…only root support (31s / no limit) M [ **] A start job is running for Configur…only root support (32s / no limit) M [ ***] A start job is running for Configur…only root support (32s / no limit) M [ *** ] A start job is running for Configur…only root support (33s / no limit) M [ *** ] A start job is running for Configur…only root support (33s / no limit) M [*** ] A start job is running for Configur…only root support (34s / no limit) M [** ] A start job is running for Configur…only root support (34s / no limit) M [* ] A start job is running for Configur…only root support (35s / no limit) M [** ] A start job is running for Configur…only root support (35s / no limit) M [*** ] A start job is running for Configur…only root support (36s / no limit) M [ *** ] A start job is running for Configur…only root support (36s / no limit) M [ *** ] A start job is running for Configur…only root support (37s / no limit) M [ ***] A start job is running for Configur…only root support (37s / no limit) M [ **] A start job is running for Configur…only root support (38s / no limit) M [ *] A start job is running for Configur…only root support (38s / no limit) M [ **] A start job is running for Configur…only root support (39s / no limit) M [ ***] A start job is running for Configur…only root support (39s / no limit) M [ *** ] A start job is running for Configur…only root support (40s / no limit) M [ *** ] A start job is running for Configur…only root support (40s / no limit) M [*** ] A start job is running for Configur…only root support (41s / no limit) M [** ] A start job is running for Configur…only root support (41s / no limit) M [* ] A start job is running for Configur…only root support (42s / no limit) M [** ] A start job is running for Configur…only root support (42s / no limit) M [*** ] A start job is running for Configur…only root support (43s / no limit) M [ *** ] A start job is running for Configur…only root support (43s / no limit) M [ *** ] A start job is running for Configur…only root support (44s / no limit) M [ ***] A start job is running for Configur…only root support (44s / no limit) [ 192.461266] workqueue: do_free_init hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND M [ **] A start job is running for Configur…only root support (45s / no limit) M [ *] A start job is running for Configur…only root support (45s / no limit) M [ **] A start job is running for Configur…only root support (46s / no limit) M [ ***] A start job is running for Configur…only root support (46s / no limit) M [ OK ] Finished Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Load/Save OS Random Seed... Starting Create Volatile Files and Directories... [ OK ] Finished Mark the need to relabel after reboot. [ OK ] Finished Load/Save OS Random Seed. [ OK ] Finished Create Volatile Files and Directories. Starting RPC Bind... Starting Record System Boot/Shutdown in UTMP... [ OK ] Started RPC Bind. [ OK ] Finished Record System Boot/Shutdown in UTMP. [ *** ] A start job is running for Rebuild …amic Linker Cache (52s / no limit) M [ *** ] A start job is running for Rebuild …amic Linker Cache (52s / no limit) M [*** ] A start job is running for Rebuild …amic Linker Cache (53s / no limit) M [** ] A start job is running for Rebuild …amic Linker Cache (53s / no limit) M [* ] A start job is running for Rebuild …amic Linker Cache (54s / no limit) M [** ] A start job is running for Rebuild …amic Linker Cache (54s / no limit) M [*** ] A start job is running for Rebuild …amic Linker Cache (55s / no limit) M [ *** ] A start job is running for Rebuild …amic Linker Cache (55s / no limit) M [ *** ] A start job is running for Rebuild …amic Linker Cache (56s / no limit) M [ ***] A start job is running for Rebuild …amic Linker Cache (56s / no limit) M [ **] A start job is running for Rebuild …amic Linker Cache (57s / no limit) M [ OK ] Finished Rebuild Dynamic Linker Cache.  Starting Update is Completed... [ OK ] Finished Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timer Units. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Socket Units. Starting D-Bus System Message Bus... [ OK ] Started D-Bus System Message Bus. [ OK ] Reached target Basic System. Starting Network Manager... Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 207.993986] workqueue: wait_rcu_exp_gp hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND Starting RealtimeKit Scheduling Policy Service... [ OK ] Reached target sshd-keygen.target. Starting User Login Management... Starting Daemon for power management... [ OK ] Finished Restore /run/initramfs on shutdown. [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [FAILED] Failed to start Daemon for power management. See 'systemctl status upower.service' for details. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Stopped Daemon for power management. Starting Daemon for power management... [FAILED] Failed to start Daemon for power management. See 'systemctl status upower.service' for details. [ OK ] Started RealtimeKit Scheduling Policy Service. Starting Hostname Service... [ OK ] Stopped Daemon for power management. Starting Daemon for power management... [ OK ] Finished Load Kernel Module drm. [FAILED] Failed to start Daemon for power management. See 'systemctl status upower.service' for details. Starting User Login Management... [ OK ] Stopped Daemon for power management. Starting Daemon for power management... [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [FAILED] Failed to start Daemon for power management. See 'systemctl status upower.service' for details. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Stopped Daemon for power management. Starting Daemon for power management... [FAILED] Failed to start Daemon for power management. See 'systemctl status upower.service' for details. [ OK ] Finished Load Kernel Module drm. [ OK ] Started Hostname Service. Starting User Login Management... [ OK ] Stopped Daemon for power management. [FAILED] Failed to start Daemon for power management. See 'systemctl status upower.service' for details. [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. [ OK ] Finished Load Kernel Module drm. Starting User Login Management... [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. Starting Network Manager Script Dispatcher Service... [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Finished Load Kernel Module drm. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Network Manager Wait Online... Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting User Login Management... Starting Dynamic System Tuning Daemon... [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started OpenSSH server daemon. [ OK ] Finished Load Kernel Module drm. [ OK ] Reached target NFS client services. [ OK ] Reached target Preparation for Remote File Systems. [ OK ] Reached target Remote File Systems. Starting User Login Management... Starting Permit User Sessions... [ OK ] Finished Network Manager Wait Online. [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... Starting System Logging Service... [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Finished Permit User Sessions. [ OK ] Started Notify NFS peers of a restart. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Finished Load Kernel Module drm. Starting User Login Management... [ OK ] Started System Logging Service. [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Finished Load Kernel Module drm. Starting User Login Management... [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Finished Load Kernel Module drm. Starting User Login Management... [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Finished Load Kernel Module drm. Starting User Login Management... [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. [ OK ] Stopped User Login Management. Starting Load Kernel Module drm... [ OK ] Finished Load Kernel Module drm. [FAILED] Failed to start User Login Management. See 'systemctl status systemd-logind.service' for details. Rocky Linux 9.5 (Blue Onyx) Kernel 5.14.0rocky95-debug on an x86_64 oleg608-server login: [ 228.814658] workqueue: delayed_vfree_work hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 241.959814] workqueue: blk_mq_run_work_fn hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 244.861267] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 245.028267] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 259.097320] workqueue: delayed_vfree_work hogged CPU for >10000us 19 times, consider switching to WQ_UNBOUND [ 289.768266] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND [ 319.144263] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 442.362183] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 19 times, consider switching to WQ_UNBOUND [ 485.474162] workqueue: kernfs_notify_workfn hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 488.343612] workqueue: delayed_vfree_work hogged CPU for >10000us 35 times, consider switching to WQ_UNBOUND [ 513.585504] libcfs: loading out-of-tree module taints kernel. [ 513.597158] libcfs: module verification failed: signature and/or required key missing - tainting kernel [ 513.888112] Key type ._llcrypt registered [ 513.888148] Key type .llcrypt registered [ 514.906845] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_hostid [ 561.249390] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing load_modules_local [ 573.330224] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 573.723016] alg: No test for adler32 (adler32-zlib) [ 578.867085] Lustre: Lustre: Build Version: 2.16.52_73_g6bb624e [ 584.863965] LNet: Added LNI 192.168.206.108@tcp [8/256/0/180] [ 584.868007] LNet: Accept secure, port 988 [ 587.973793] Key type lgssc registered [ 599.509952] Lustre: Echo OBD driver; http://www.lustre.org/ [ 610.946088] debugfs: Directory 'extent_status' with parent 'slab' already present! [ 610.960763] debugfs: Directory 'pending_reservation' with parent 'slab' already present! [ 610.962607] debugfs: Directory 'bio_post_read_ctx' with parent 'slab' already present! [ 611.074275] workqueue: do_free_init hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 634.777222] workqueue: kernfs_notify_workfn hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 694.753221] ZFS: Loaded module v2.3.0-1, ZFS pool version 5000, ZFS filesystem version 5 [ 694.791683] modprobe (4875) used greatest stack depth: 18600 bytes left [ 706.352389] LDISKFS-fs (vdc): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 706.437106] LDISKFS-fs (vdc): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [ 769.715954] LDISKFS-fs (vdd): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 769.849318] LDISKFS-fs (vdd): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [ 804.395336] workqueue: css_killed_work_fn hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 822.180710] LDISKFS-fs (vde): mounted filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f r/w with ordered data mode. Quota mode: journalled. [ 822.342080] LDISKFS-fs (vde): unmounting filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f. [ 872.813376] LDISKFS-fs (vdf): mounted filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739 r/w with ordered data mode. Quota mode: journalled. [ 872.887711] LDISKFS-fs (vdf): unmounting filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739. [ 950.353295] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing load_modules_local [ 1032.916260] workqueue: delayed_vfree_work hogged CPU for >10000us 67 times, consider switching to WQ_UNBOUND [ 1050.495081] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 1050.624350] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [ 1050.726813] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 1050.785085] ------------[ cut here ]------------ [ 1050.785113] DEBUG_LOCKS_WARN_ON(!lockdep_enabled()) [ 1050.788223] WARNING: CPU: 2 PID: 7481 at kernel/locking/lockdep.c:4911 lockdep_init_map_type+0x4b1/0x810 [ 1050.788321] Modules linked in: zfs(O) spl(O) lustre(OE) osp(OE) ofd(OE) lod(OE) mdt(OE) mdd(OE) mgs(OE) osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) lfsck(OE) obdecho(OE) mgc(OE) mdc(OE) lov(OE) osc(OE) lmv(OE) fid(OE) fld(OE) ptlrpc_gss(OE) ptlrpc(OE) obdclass(OE) ksocklnd(OE) lnet(OE) libcfs(OE) dm_flakey rfkill rpcsec_gss_krb5 auth_rpcgss intel_rapl_msr intel_rapl_common kvm_intel kvm rapl i2c_piix4 pcspkr joydev squashfs drm fuse ext4 mbcache jbd2 crct10dif_pclmul crc32_pclmul crc32c_intel ata_generic ata_piix ghash_clmulni_intel libata serio_raw dm_mirror dm_region_hash dm_log dm_mod [ 1050.788441] CPU: 2 PID: 7481 Comm: mount.lustre Kdump: loaded Tainted: G OE ------- --- 5.14.0rocky95-debug #3 [ 1050.788449] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 1050.788453] RIP: 0010:lockdep_init_map_type+0x4b1/0x810 [ 1050.788463] Code: 08 84 d2 0f 85 2c 03 00 00 8b 05 ee f2 64 04 85 c0 0f 85 8e fd ff ff 48 c7 c6 00 b7 4e b6 48 c7 c7 a0 9d 4e b6 e8 4f 45 e7 ff <0f> 0b e9 74 fd ff ff e8 c3 ca ee 00 85 c0 74 4f 48 c7 c0 d4 74 3d [ 1050.788469] RSP: 0018:ffffc900061d6c50 EFLAGS: 00010286 [ 1050.788476] RAX: 0000000000000000 RBX: ffff88811cffba80 RCX: 0000000000000000 [ 1050.788480] RDX: 0000000000000002 RSI: ffffffffb67a8ae0 RDI: 0000000000000001 [ 1050.788484] RBP: ffff88801b65a4c8 R08: 0000000000000001 R09: ffffed1023fffd88 [ 1050.788488] R10: ffff88811fffec47 R11: ffffffffb7a57d08 R12: ffffffffc26d1820 [ 1050.788492] R13: 0000000000000002 R14: 0000000000000001 R15: 0000000000000000 [ 1050.788495] FS: 00007f1ae2c61b00(0000) GS:ffff88811fe00000(0000) knlGS:0000000000000000 [ 1050.788505] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1050.788510] CR2: 0000562f32cd2cb8 CR3: 0000000112b7a001 CR4: 0000000000170ef0 [ 1050.788515] Call Trace: [ 1050.788522] [ 1050.788530] ? show_trace_log_lvl+0x1c4/0x2db [ 1050.788540] ? show_trace_log_lvl+0x1c4/0x2db [ 1050.788552] ? ldiskfs_quota_enable.constprop.0+0x319/0x620 [ldiskfs] [ 1050.788668] ? lockdep_init_map_type+0x4b1/0x810 [ 1050.788677] ? __warn+0xce/0x180 [ 1050.788686] ? lockdep_init_map_type+0x4b1/0x810 [ 1050.788693] ? report_bug+0x1eb/0x360 [ 1050.788706] ? handle_bug+0x3c/0x70 [ 1050.788717] ? exc_invalid_op+0x14/0x40 [ 1050.788724] ? asm_exc_invalid_op+0x16/0x20 [ 1050.788739] ? lockdep_init_map_type+0x4b1/0x810 [ 1050.788751] ldiskfs_quota_enable.constprop.0+0x319/0x620 [ldiskfs] [ 1050.788861] ? entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 1050.788871] ? ldiskfs_mark_dquot_dirty+0x170/0x170 [ldiskfs] [ 1050.788974] ? ldiskfs_register_li_request+0x365/0x8a0 [ldiskfs] [ 1050.789073] ? lock_release+0x70/0x330 [ 1050.789081] ? __mutex_unlock_slowpath+0x161/0x5e0 [ 1050.789087] ? mutex_lock_io_nested+0x13a3/0x1430 [ 1050.789095] ldiskfs_enable_quotas+0x23f/0x500 [ldiskfs] [ 1050.789216] ? ldiskfs_force_commit+0xa0/0xa0 [ldiskfs] [ 1050.789363] ? ldiskfs_register_li_request+0x50b/0x8a0 [ldiskfs] [ 1050.789463] __ldiskfs_fill_super+0x51d8/0x5880 [ldiskfs] [ 1050.800180] ? ldiskfs_reconfigure+0x390/0x390 [ldiskfs] [ 1050.800345] ? __kmalloc_large_node+0xfa/0x140 [ 1050.800364] ldiskfs_fill_super+0x2a6/0xa20 [ldiskfs] [ 1050.800492] ? __ldiskfs_fill_super+0x5880/0x5880 [ldiskfs] [ 1050.800602] ? down_write+0xb7/0x1b0 [ 1050.800612] ? rwsem_down_write_slowpath+0xa50/0xa50 [ 1050.800621] ? sb_set_blocksize+0x3e/0xe0 [ 1050.800631] ? setup_bdev_super+0x2d9/0x600 [ 1050.800643] get_tree_bdev+0x348/0x5a0 [ 1050.800652] ? __ldiskfs_fill_super+0x5880/0x5880 [ldiskfs] [ 1050.800779] ? sget_dev+0xd0/0xd0 [ 1050.800787] ? security_sb_eat_lsm_opts+0x41/0x80 [ 1050.800800] ? generic_parse_monolithic+0x9f/0x190 [ 1050.800808] ? __kasan_kmalloc+0x77/0x90 [ 1050.800819] ? vfs_parse_fs_string+0x130/0x130 [ 1050.800830] vfs_get_tree+0x84/0x2e0 [ 1050.800839] vfs_kern_mount.part.0+0x75/0x100 [ 1050.800850] osd_mount+0x9a6/0x1f60 [osd_ldiskfs] [ 1050.800947] ? osd_create+0x1550/0x1550 [osd_ldiskfs] [ 1050.801030] ? target_name2index+0x280/0x280 [obdclass] [ 1050.801367] osd_device_init0+0x5c5/0x15f0 [osd_ldiskfs] [ 1050.801465] osd_device_alloc+0x259/0x3a0 [osd_ldiskfs] [ 1050.801542] obd_setup+0x289/0x7a0 [obdclass] [ 1050.801805] ? obd_iocontrol.constprop.0.isra.0+0x7c0/0x7c0 [obdclass] [ 1050.802071] ? static_obj+0x98/0xd0 [ 1050.802082] ? lockdep_init_map_type+0x2fb/0x810 [ 1050.802093] ? cfs_hash_create+0x823/0x1590 [obdclass] [ 1050.802393] class_setup+0xb9b/0x1270 [obdclass] [ 1050.802667] ? _raw_spin_unlock_irqrestore+0x3a/0x60 [ 1050.802681] class_process_config+0x2552/0x3940 [obdclass] [ 1050.802990] ? class_cleanup+0xe90/0xe90 [obdclass] [ 1050.810955] ? __kmem_cache_alloc_node+0x24b/0x3b0 [ 1050.810972] ? do_lcfg+0x269/0x9c0 [obdclass] [ 1050.811275] ? lustre_cfg_init+0x198/0x2d0 [obdclass] [ 1050.811546] do_lcfg+0x47d/0x9c0 [obdclass] [ 1050.811812] ? lustre_process_log+0x14d0/0x14d0 [obdclass] [ 1050.812081] ? do_raw_spin_unlock+0x149/0x1f0 [ 1050.812094] ? _raw_spin_unlock+0x29/0x40 [ 1050.812104] ? class_name2obd+0x18d/0x1f0 [obdclass] [ 1050.812368] lustre_start_simple+0x12d/0x250 [obdclass] [ 1050.812619] osd_start+0x921/0xe70 [ptlrpc] [ 1050.813059] ? lustre_register_lwp_item+0xcd0/0xcd0 [ptlrpc] [ 1050.813476] ? lsi_prepare+0x62f/0xc90 [ptlrpc] [ 1050.813799] ? lustre_lwp_setup+0x14e0/0x14e0 [ptlrpc] [ 1050.814163] ? cfs_trace_put_tcd+0xe0/0xe0 [libcfs] [ 1050.814214] server_fill_super+0x1cd/0x1000 [ptlrpc] [ 1050.814589] ? server_start_targets+0x1d90/0x1d90 [ptlrpc] [ 1050.814942] ? class_num2obd+0x20/0x20 [obdclass] [ 1050.815170] ? lockdep_init_map_type+0x2fb/0x810 [ 1050.815186] ? lustre_fill_super+0x1bd/0xa10 [lustre] [ 1050.815364] lustre_fill_super+0x7b3/0xa10 [lustre] [ 1050.815486] ? ll_inode_destroy_callback+0x150/0x150 [lustre] [ 1050.815609] mount_nodev+0x41/0xd0 [ 1050.815620] ? lustre_kill_super+0x90/0x90 [lustre] [ 1050.815741] legacy_get_tree+0xff/0x1f0 [ 1050.815752] vfs_get_tree+0x84/0x2e0 [ 1050.815760] do_new_mount+0x224/0x550 [ 1050.815770] ? do_add_mount+0x370/0x370 [ 1050.815777] ? security_capable+0x50/0x90 [ 1050.815787] path_mount+0x2d2/0x1500 [ 1050.815794] ? user_path_at_empty+0x45/0x50 [ 1050.815803] ? finish_automount+0x6c0/0x6c0 [ 1050.815808] ? kmem_cache_free+0xf9/0x3d0 [ 1050.815822] __x64_sys_mount+0x1fa/0x270 [ 1050.815829] ? path_mount+0x1500/0x1500 [ 1050.815835] ? __lock_release+0x4bb/0x9f0 [ 1050.815843] ? lock_downgrade+0x130/0x130 [ 1050.815851] do_syscall_64+0x59/0xe0 [ 1050.815860] ? lock_acquire+0x164/0x3c0 [ 1050.815869] ? strict_work_handler+0x1c0/0x1c0 [ 1050.815880] ? __might_fault+0x4d/0x70 [ 1050.815887] ? rseq_ip_fixup+0x31d/0x550 [ 1050.815897] ? file_init_path+0x620/0x620 [ 1050.815904] ? xfd_validate_state+0x24/0x120 [ 1050.815912] ? restore_fpregs_from_fpstate+0x95/0x170 [ 1050.815921] ? kernel_fpu_begin_mask+0x1d0/0x1d0 [ 1050.815931] ? fpregs_restore_userregs+0x164/0x300 [ 1050.815939] ? exit_to_user_mode_prepare+0xff/0x110 [ 1050.815946] ? syscall_exit_to_user_mode+0x19/0x30 [ 1050.815951] ? do_syscall_64+0x65/0xe0 [ 1050.815957] ? exit_to_user_mode_prepare+0x43/0x110 [ 1050.815963] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 1050.815971] RIP: 0033:0x7f1ae2b0f13e [ 1050.816009] Code: 48 8b 0d dd 9c 0e 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d aa 9c 0e 00 f7 d8 64 89 01 48 [ 1050.816014] RSP: 002b:00007ffce4cd60c8 EFLAGS: 00000286 ORIG_RAX: 00000000000000a5 [ 1050.816023] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f1ae2b0f13e [ 1050.816027] RDX: 00000000004320c9 RSI: 00007ffce4cdc330 RDI: 00000000015edb40 [ 1050.816031] RBP: 00000000015edb60 R08: 00000000015edb60 R09: 0000000000000040 [ 1050.816035] R10: 0000000001000000 R11: 0000000000000286 R12: 00007ffce4cdc330 [ 1050.816038] R13: 00000000004320c9 R14: 0000000001000000 R15: 00000000fffffff5 [ 1050.816049] [ 1050.816052] ---[ end trace 0000000000000000 ]--- [ 1050.940171] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 1052.923691] ------------[ cut here ]------------ [ 1052.923719] refcount_t: decrement hit 0; leaking memory. [ 1052.923822] WARNING: CPU: 3 PID: 4125 at lib/refcount.c:31 refcount_warn_saturate+0x7d/0x140 [ 1052.923844] Modules linked in: zfs(O) spl(O) lustre(OE) osp(OE) ofd(OE) lod(OE) mdt(OE) mdd(OE) mgs(OE) osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) lfsck(OE) obdecho(OE) mgc(OE) mdc(OE) lov(OE) osc(OE) lmv(OE) fid(OE) fld(OE) ptlrpc_gss(OE) ptlrpc(OE) obdclass(OE) ksocklnd(OE) lnet(OE) libcfs(OE) dm_flakey rfkill rpcsec_gss_krb5 auth_rpcgss intel_rapl_msr intel_rapl_common kvm_intel kvm rapl i2c_piix4 pcspkr joydev squashfs drm fuse ext4 mbcache jbd2 crct10dif_pclmul crc32_pclmul crc32c_intel ata_generic ata_piix ghash_clmulni_intel libata serio_raw dm_mirror dm_region_hash dm_log dm_mod [ 1052.924118] CPU: 3 PID: 4125 Comm: socknal_cd02 Kdump: loaded Tainted: G W OE ------- --- 5.14.0rocky95-debug #3 [ 1052.924127] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 1052.924134] RIP: 0010:refcount_warn_saturate+0x7d/0x140 [ 1052.924144] Code: 1f 3b 6e 03 00 0f 84 ba 00 00 00 5b 5d c3 80 3d 0e 3b 6e 03 00 75 f4 48 c7 c7 00 0b 7a b6 c6 05 fe 3a 6e 03 01 e8 03 ed f5 fe <0f> 0b eb dd 80 3d f2 3a 6e 03 00 75 d4 48 c7 c7 a0 09 7a b6 c6 05 [ 1052.924151] RSP: 0018:ffffc90001dbfa40 EFLAGS: 00010282 [ 1052.924162] RAX: 0000000000000000 RBX: ffffffffba7cd574 RCX: 0000000000000000 [ 1052.924170] RDX: 0000000000000002 RSI: ffffffffb67a8ae0 RDI: 0000000000000001 [ 1052.924176] RBP: 0000000000000004 R08: 0000000000000001 R09: ffffed102407fd88 [ 1052.924183] R10: ffff8881203fec47 R11: ffffffffb7a58998 R12: 1ffff920003b7f4c [ 1052.924199] R13: 00000000ffffffef R14: ffffffffba7cd574 R15: 0000000000000002 [ 1052.924208] FS: 0000000000000000(0000) GS:ffff888120200000(0000) knlGS:0000000000000000 [ 1052.924220] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1052.924229] CR2: 00007f74dbf954d0 CR3: 0000000111891002 CR4: 0000000000170ef0 [ 1052.924296] Call Trace: [ 1052.924304] [ 1052.924311] ? show_trace_log_lvl+0x1c4/0x2db [ 1052.924326] ? show_trace_log_lvl+0x1c4/0x2db [ 1052.924343] ? ref_tracker_free+0x481/0x600 [ 1052.924357] ? refcount_warn_saturate+0x7d/0x140 [ 1052.924367] ? __warn+0xce/0x180 [ 1052.924380] ? refcount_warn_saturate+0x7d/0x140 [ 1052.924391] ? report_bug+0x1eb/0x360 [ 1052.924407] ? handle_bug+0x3c/0x70 [ 1052.924420] ? exc_invalid_op+0x14/0x40 [ 1052.924431] ? asm_exc_invalid_op+0x16/0x20 [ 1052.924449] ? refcount_warn_saturate+0x7d/0x140 [ 1052.924460] ref_tracker_free+0x481/0x600 [ 1052.924470] ? _raw_spin_unlock+0x29/0x40 [ 1052.924483] ? ref_tracker_dir_exit+0x690/0x690 [ 1052.924495] ? sk_stream_kill_queues+0x147/0x380 [ 1052.924508] ? do_raw_spin_trylock+0xb5/0x180 [ 1052.924521] ? do_raw_spin_lock+0x270/0x270 [ 1052.924532] ? lock_acquire+0x82/0x3c0 [ 1052.924542] ? inet_sock_destruct+0x569/0x820 [ 1052.924556] __sk_destruct+0x2c1/0x510 [ 1052.924568] inet_release+0xf4/0x220 [ 1052.924580] sock_release+0x82/0x190 [ 1052.924594] lnet_sock_connect+0xce/0x350 [lnet] [ 1052.924726] lnet_connect.part.0+0x98/0x430 [lnet] [ 1052.924837] ? lnet_connect_console_error+0x500/0x500 [lnet] [ 1052.932299] ? do_raw_write_trylock+0xb5/0x180 [ 1052.932318] ? do_raw_write_lock+0x280/0x280 [ 1052.932326] ? lock_acquire+0x82/0x3c0 [ 1052.932335] ? ksocknal_connect+0x303/0x11d0 [ksocklnd] [ 1052.932368] ksocknal_connect+0x399/0x11d0 [ksocklnd] [ 1052.932393] ? do_raw_spin_trylock+0xb5/0x180 [ 1052.932402] ? ksocknal_txlist_done+0x620/0x620 [ksocklnd] [ 1052.932426] ? _raw_spin_lock_irqsave+0x54/0x80 [ 1052.932437] ksocknal_connd+0xa48/0xfc0 [ksocklnd] [ 1052.932465] ? ksocknal_thread_fini+0x30/0x30 [ksocklnd] [ 1052.932492] ? __kthread_parkme+0xba/0x200 [ 1052.932500] ? prepare_to_swait_exclusive+0x240/0x240 [ 1052.932509] ? __kthread_parkme+0xc7/0x200 [ 1052.932516] ? ksocknal_thread_fini+0x30/0x30 [ksocklnd] [ 1052.932541] kthread+0x2ab/0x350 [ 1052.932548] ? kthread_insert_work_sanity_check+0xd0/0xd0 [ 1052.932555] ret_from_fork+0x1f/0x30 [ 1052.932570] [ 1052.932573] ---[ end trace 0000000000000000 ]--- [ 1053.459107] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall in log lustre-MDT0000 [ 1053.576652] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1053.750910] Lustre: lustre-MDT0000: new disk, initializing [ 1054.110146] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1054.209778] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1073.047477] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1108.903793] workqueue: css_killed_work_fn hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 1131.439810] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 35 times, consider switching to WQ_UNBOUND [ 1142.862891] LDISKFS-fs (dm-1): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 1142.945079] LDISKFS-fs (dm-1): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [ 1143.138106] LDISKFS-fs (dm-1): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 1144.197626] Lustre: Modifying parameter lustre-MDT0001.mdt.identity_upcall in log lustre-MDT0001 [ 1144.258659] Lustre: 8559:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1144.378353] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1144.378396] Lustre: Skipped 1 previous similar message [ 1144.699174] Lustre: lustre-MDT0001: new disk, initializing [ 1144.959321] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1145.048390] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1145.052796] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1160.634892] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1180.899440] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 1198.578016] workqueue: kernfs_notify_workfn hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND [ 1235.165215] LDISKFS-fs (dm-2): mounted filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f r/w with ordered data mode. Quota mode: journalled. [ 1235.227647] LDISKFS-fs (dm-2): unmounting filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f. [ 1235.380571] LDISKFS-fs (dm-2): mounted filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f r/w with ordered data mode. Quota mode: journalled. [ 1236.548871] Lustre: 9683:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1236.701749] Lustre: lustre-OST0000: new disk, initializing [ 1236.732559] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1237.102199] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1244.111695] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1244.132388] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1244.710641] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1265.196551] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1333.129853] workqueue: css_killed_work_fn hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND [ 1334.319342] LDISKFS-fs (dm-3): mounted filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739 r/w with ordered data mode. Quota mode: journalled. [ 1334.377505] LDISKFS-fs (dm-3): unmounting filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739. [ 1334.503829] LDISKFS-fs (dm-3): mounted filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739 r/w with ordered data mode. Quota mode: journalled. [ 1335.264527] Lustre: 10883:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1335.373769] Lustre: lustre-OST0001: new disk, initializing [ 1335.397480] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1335.706167] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 1343.951545] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1343.960371] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1344.413810] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1359.720121] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1396.566838] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1421.693071] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 1452.335696] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing check_logdir /tmp/testlogs/ [ 1470.086575] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing yml_node [ 1486.058097] Lustre: DEBUG MARKER: Client: 2.16.52.73 [ 1498.544887] Lustre: DEBUG MARKER: MDS: 2.16.52.73 [ 1510.366118] Lustre: DEBUG MARKER: OSS: 2.16.52.73 [ 1517.787416] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity ============----- Tue Apr 1 04:19:07 EDT 2025 [ 1550.090769] workqueue: kernfs_notify_workfn hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 1607.815548] Lustre: DEBUG MARKER: - need mds1 <= 2.14.55-100-g8a84c7f9c7 for LU-14927, skip 0f [ 1614.789853] Lustre: DEBUG MARKER: - need mds1 < v2_14_55-100-g8a84c7f9c7 for LU-14927, skip 0f [ 1622.602659] Lustre: DEBUG MARKER: excepting tests: 56oc 42a 42c 42b 118c 118d 407 119i 851 817 411a [ 1629.417960] Lustre: DEBUG MARKER: skipping tests SLOW=no: 27m 60i 64b 68 71 135 136 230d 300o 842 [ 1636.591703] Lustre: DEBUG MARKER: === sanity: start setup 04:21:06 (1743495666) === [ 1652.677198] Lustre: DEBUG MARKER: oleg608-client.virtnet: executing check_config_client /mnt/lustre [ 1751.555273] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1762.611216] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 67 times, consider switching to WQ_UNBOUND [ 1767.969001] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 1781.727304] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1804.557682] Lustre: DEBUG MARKER: === sanity: finish setup 04:23:54 (1743495834) === [ 1813.527105] Lustre: DEBUG MARKER: == sanity test 0a: touch; rm ============================= 04:24:03 (1743495843) [ 1843.873723] Lustre: DEBUG MARKER: == sanity test 0b: chmod 0755 /mnt/lustre ======================================================================================= 04:24:33 (1743495873) [ 1874.466145] Lustre: DEBUG MARKER: == sanity test 0c: check import proc ===================== 04:25:04 (1743495904) [ 1904.418454] Lustre: DEBUG MARKER: == sanity test 0d: check export proc ======================================================================================= 04:25:33 (1743495933) [ 1960.079870] Lustre: DEBUG MARKER: == sanity test 0e: Enable DNE MDT balancing for mkdir in the ROOT ========================================================== 04:26:29 (1743495989) [ 1990.331830] Lustre: DEBUG MARKER: == sanity test 1: mkdir; remkdir; rmdir ================== 04:26:59 (1743496019) [ 2009.314824] workqueue: delayed_vfree_work hogged CPU for >10000us 131 times, consider switching to WQ_UNBOUND [ 2009.430230] workqueue: css_release_work_fn hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 2018.561637] Lustre: DEBUG MARKER: == sanity test 2: mkdir; touch; rmdir; check file ======== 04:27:28 (1743496048) [ 2046.790944] Lustre: DEBUG MARKER: == sanity test 3: mkdir; touch; rmdir; check dir ========= 04:27:56 (1743496076) [ 2053.841841] workqueue: css_killed_work_fn hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 2074.997684] Lustre: DEBUG MARKER: == sanity test 4: mkdir; touch dir/file; rmdir; checkdir (expect error) ========================================================== 04:28:25 (1743496105) [ 2105.285380] Lustre: DEBUG MARKER: == sanity test 5: mkdir .../d5 .../d5/d2; chmod .../d5/d2 ========================================================== 04:28:55 (1743496135) [ 2133.812972] Lustre: DEBUG MARKER: == sanity test 6a: touch f6a; chmod f6a; runas -u 500 -g 500 chmod f6a (should return error) ============================================================ 04:29:24 (1743496164) [ 2162.653688] Lustre: DEBUG MARKER: == sanity test 6c: touch f6c; chown f6c; runas -u 500 -g 500 chown f6c (should return error) ============================================================ 04:29:52 (1743496192) [ 2195.659280] Lustre: DEBUG MARKER: == sanity test 6e: touch+chgrp ; runas -u 500 -g 500 chgrp (should return error) ========================================================== 04:30:24 (1743496224) [ 2224.509172] Lustre: DEBUG MARKER: == sanity test 6g: verify new dir in sgid dir inherits group ========================================================== 04:30:55 (1743496255) [ 2255.503164] Lustre: DEBUG MARKER: == sanity test 6h: runas -u 500 -g 500 chown RUNAS_ID.0 .../ (should return error) ========================================================== 04:31:25 (1743496285) [ 2260.189195] workqueue: kernfs_notify_workfn hogged CPU for >10000us 19 times, consider switching to WQ_UNBOUND [ 2283.478582] Lustre: DEBUG MARKER: == sanity test 6i: touch+chmod+chgrp ; chgrp read-only file should succeed ========================================================== 04:31:53 (1743496313) [ 2301.709489] workqueue: css_release_work_fn hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 2310.617370] Lustre: DEBUG MARKER: == sanity test 7a: mkdir .../d7; mcreate .../d7/f; chmod .../d7/f ============================================================== 04:32:21 (1743496341) [ 2338.129384] Lustre: DEBUG MARKER: == sanity test 7b: mkdir .../d7; mcreate d7/f2; echo foo > d7/f2 =============================================================== 04:32:49 (1743496369) [ 2367.880378] Lustre: DEBUG MARKER: == sanity test 8: mkdir .../d8; touch .../d8/f; chmod .../d8/f ================================================================= 04:33:17 (1743496397) [ 2398.169450] Lustre: DEBUG MARKER: == sanity test 9: mkdir .../d9 .../d9/d2 .../d9/d2/d3 ========================================================================== 04:33:48 (1743496428) [ 2425.753417] Lustre: DEBUG MARKER: == sanity test 10: mkdir .../d10 .../d10/d2; touch .../d10/d2/f ================================================================ 04:34:16 (1743496456) [ 2454.909151] Lustre: DEBUG MARKER: == sanity test 11: mkdir .../d11 d11/d2; chmod .../d11/d2 ====================================================================== 04:34:44 (1743496484) [ 2483.893682] Lustre: DEBUG MARKER: == sanity test 12: touch .../d12/f; chmod .../d12/f .../d12/f ================================================================== 04:35:14 (1743496514) [ 2513.179142] Lustre: DEBUG MARKER: == sanity test 13: creat .../d13/f; dd .../d13/f; > .../d13/f ================================================================== 04:35:43 (1743496543) [ 2540.190079] Lustre: DEBUG MARKER: == sanity test 14: touch .../d14/f; rm .../d14/f; rm .../d14/f ================================================================= 04:36:11 (1743496571) [ 2568.611897] Lustre: DEBUG MARKER: == sanity test 15: touch .../d15/f; mv .../d15/f .../d15/f2 ==================================================================== 04:36:39 (1743496599) [ 2598.931522] Lustre: DEBUG MARKER: == sanity test 16: touch .../d16/f; rm -rf .../d16/f ===== 04:37:08 (1743496628) [ 2627.866640] Lustre: DEBUG MARKER: == sanity test 17a: symlinks: create, remove (real) ====== 04:37:38 (1743496658) [ 2658.159674] Lustre: DEBUG MARKER: == sanity test 17b: symlinks: create, remove (dangling) == 04:38:07 (1743496687) [ 2690.019723] Lustre: DEBUG MARKER: == sanity test 17c: symlinks: open dangling (should return error) ========================================================== 04:38:38 (1743496718) [ 2723.161012] Lustre: DEBUG MARKER: == sanity test 17d: symlinks: create dangling ============ 04:39:12 (1743496752) [ 2754.191336] Lustre: DEBUG MARKER: == sanity test 17e: symlinks: create recursive symlink (should return error) ========================================================== 04:39:43 (1743496783) [ 2783.768501] Lustre: DEBUG MARKER: == sanity test 17f: symlinks: long and very long symlink name ========================================================== 04:40:14 (1743496814) [ 2814.640557] Lustre: DEBUG MARKER: == sanity test 17g: symlinks: really long symlink name and inode boundaries ========================================================== 04:40:45 (1743496845) [ 2845.051726] Lustre: DEBUG MARKER: == sanity test 17h: create objects: lov_free_memmd() doesn't lbug ========================================================== 04:41:14 (1743496874) [ 2880.759047] Lustre: DEBUG MARKER: == sanity test 17i: don't panic on short symlink (should return error) ========================================================== 04:41:49 (1743496909) [ 2887.568365] Lustre: *** cfs_fail_loc=143, val=0*** [ 2916.844804] Lustre: DEBUG MARKER: == sanity test 17k: symlinks: rsync with xattrs enabled == 04:42:27 (1743496947) [ 2946.075448] Lustre: DEBUG MARKER: == sanity test 17l: Ensure lgetxattr's returned xattr size is consistent ========================================================== 04:42:56 (1743496976) [ 2976.101187] Lustre: DEBUG MARKER: == sanity test 17m: run e2fsck against MDT which contains short/long symlink ========================================================== 04:43:26 (1743497006) [ 3131.916669] Lustre: Failing over lustre-MDT0001 [ 3132.350678] workqueue: drain_vmap_area_work hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 3132.649145] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3132.657978] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3133.239363] LDISKFS-fs (dm-1): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [ 3133.407508] Lustre: server umount lustre-MDT0001 complete [ 3137.786655] LustreError: 9970:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3137.786702] LustreError: 9970:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 3 previous similar messages [ 3140.910663] LustreError: 7507:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.206.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3140.914504] LustreError: 7507:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 2 previous similar messages [ 3142.890348] LustreError: 25250:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3145.995092] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.206.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3145.995128] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 2 previous similar messages [ 3151.087342] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.206.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3151.087387] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 3 previous similar messages [ 3161.334951] LustreError: 9970:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.206.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3161.334987] LustreError: 9970:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 7 previous similar messages [ 3178.748630] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3178.748660] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 12 previous similar messages [ 3188.757391] LDISKFS-fs (dm-1): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 3189.313558] Lustre: 26241:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 3190.442824] Lustre: lustre-MDT0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3190.665665] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3191.867450] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3195.738369] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3195.837104] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 3195.923934] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:8 to 0x280000400:33) [ 3195.934211] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:9 to 0x2c0000400:33) [ 3207.429447] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3283.075546] Lustre: DEBUG MARKER: == sanity test 17n: run e2fsck against master/slave MDT which contains remote dir ========================================================== 04:48:34 (1743497314) [ 3303.013955] Lustre: Failing over lustre-MDT0000 [ 3303.165066] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3303.165115] Lustre: Skipped 2 previous similar messages [ 3303.223762] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3303.223786] Lustre: Skipped 1 previous similar message [ 3303.490485] workqueue: free_work [libcfs] hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 3303.822466] workqueue: free_work [libcfs] hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 3304.324209] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [ 3304.486139] Lustre: server umount lustre-MDT0000 complete [ 3304.726888] LustreError: 9713:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3304.726920] LustreError: 9713:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 10 previous similar messages [ 3307.766978] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3307.767045] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3307.767077] Lustre: Skipped 2 previous similar messages [ 3324.666979] Lustre: 4136:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497345/real 1743497345] req@ffff8881082fd540 x1828186617922944/t0(0) o400->MGC192.168.206.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1743497361 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 3324.667172] LustreError: MGC192.168.206.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3355.970363] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 3369.771119] LustreError: 4134:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff888107923740 x1828186617939072/t0(0) o250->MGC192.168.206.108@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 3369.776878] LustreError: 9970:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3369.776894] LustreError: 9970:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 65 previous similar messages [ 3369.831795] Lustre: Evicted from MGS (at 192.168.206.108@tcp) after server handle changed from 0x0 to 0x242620d573d250dd [ 3369.838305] Lustre: MGC192.168.206.108@tcp: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3369.838321] Lustre: Skipped 2 previous similar messages [ 3370.681791] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3370.944862] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3371.275747] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3375.882787] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3375.928816] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 3376.030931] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:65) [ 3376.030985] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:44 to 0x2c0000401:65) [ 3387.141597] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3408.067349] Lustre: Failing over lustre-MDT0001 [ 3408.593250] workqueue: free_work [libcfs] hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND [ 3409.010256] workqueue: drain_vmap_area_work hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 3409.120557] LDISKFS-fs (dm-1): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [ 3409.281977] Lustre: server umount lustre-MDT0001 complete [ 3411.702515] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3411.723098] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3460.454663] LDISKFS-fs (dm-1): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 3460.747042] Lustre: 28792:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 3461.786939] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3461.944531] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3463.183296] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3467.029468] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3467.029514] Lustre: Skipped 3 previous similar messages [ 3467.118295] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 3467.215438] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:49 to 0x2c0000400:65) [ 3467.221467] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:49 to 0x280000400:65) [ 3476.221857] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3499.755878] Lustre: Failing over lustre-MDT0000 [ 3500.259377] workqueue: free_work [libcfs] hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 3500.440183] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [ 3500.547035] Lustre: server umount lustre-MDT0000 complete [ 3501.828346] LustreError: lustre-MDT0000-osp-MDT0001: operation out_update to node 0@lo failed: rc = -107 [ 3501.828418] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3501.828452] Lustre: Skipped 2 previous similar messages [ 3501.839291] LustreError: 9702:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3501.839311] LustreError: 9702:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 43 previous similar messages [ 3519.718946] Lustre: 4136:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497540/real 1743497540] req@ffff888107921e40 x1828186618048512/t0(0) o400->MGC192.168.206.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1743497556 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 3519.719106] LustreError: MGC192.168.206.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3548.301799] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 3566.873936] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3567.043674] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3567.256103] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3571.964680] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3571.964724] Lustre: Skipped 2 previous similar messages [ 3572.006573] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 3572.086913] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:97) [ 3572.089129] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:44 to 0x2c0000401:97) [ 3580.291774] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3597.979011] Lustre: Failing over lustre-MDT0001 [ 3598.347252] workqueue: rht_deferred_worker hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 3598.532166] LDISKFS-fs (dm-1): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [ 3598.667001] Lustre: server umount lustre-MDT0001 complete [ 3602.154013] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3602.154078] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3602.154106] Lustre: Skipped 3 previous similar messages [ 3638.090337] workqueue: process_srcu hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 3647.227783] LDISKFS-fs (dm-1): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 3647.544971] Lustre: 31076:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 3648.523071] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3648.650887] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3650.455128] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3653.901450] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3653.901478] Lustre: Skipped 3 previous similar messages [ 3653.956849] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 3654.029703] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:49 to 0x280000400:97) [ 3654.029893] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:49 to 0x2c0000400:97) [ 3662.221411] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3702.070129] Lustre: Failing over lustre-MDT0000 [ 3702.865733] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [ 3702.924202] Lustre: server umount lustre-MDT0000 complete [ 3704.552896] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3704.552943] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3704.552965] Lustre: Skipped 2 previous similar messages [ 3720.421390] Lustre: 4138:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497742/real 1743497742] req@ffff8880365a1e40 x1828186618300032/t0(0) o400->MGC192.168.206.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1743497758 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 3720.421562] LustreError: MGC192.168.206.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3742.242625] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 3746.042190] Lustre: Evicted from MGS (at 192.168.206.108@tcp) after server handle changed from 0x0 to 0x242620d573d2bec9 [ 3746.047882] Lustre: MGC192.168.206.108@tcp: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3746.047909] Lustre: Skipped 2 previous similar messages [ 3746.712379] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3746.899328] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3748.079564] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3752.243917] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 3752.295370] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:123 to 0x2c0000401:161) [ 3752.301383] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:123 to 0x280000401:161) [ 3759.516510] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3774.472167] Lustre: Failing over lustre-MDT0001 [ 3774.931291] workqueue: drain_vmap_area_work hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND [ 3775.054255] workqueue: free_work [libcfs] hogged CPU for >10000us 19 times, consider switching to WQ_UNBOUND [ 3775.112946] LDISKFS-fs (dm-1): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [ 3775.185462] Lustre: server umount lustre-MDT0001 complete [ 3777.267654] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3777.267709] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3777.267738] Lustre: Skipped 3 previous similar messages [ 3777.274464] LustreError: 9702:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3777.274483] LustreError: 9702:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 161 previous similar messages [ 3814.515944] LDISKFS-fs (dm-1): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 3814.830795] Lustre: 33356:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 3815.760575] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3815.913721] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3817.029080] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3820.814349] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3820.814387] Lustre: Skipped 4 previous similar messages [ 3820.857564] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 3820.895600] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:123 to 0x280000400:161) [ 3820.895600] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:123 to 0x2c0000400:161) [ 3828.992096] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3851.645379] Lustre: Failing over lustre-MDT0000 [ 3852.272347] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [ 3852.338982] Lustre: server umount lustre-MDT0000 complete [ 3852.535869] LustreError: lustre-MDT0000-osp-MDT0001: operation out_update to node 0@lo failed: rc = -107 [ 3852.535929] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3852.535934] Lustre: Skipped 2 previous similar messages [ 3859.415255] workqueue: bpf_prog_free_deferred hogged CPU for >10000us 131 times, consider switching to WQ_UNBOUND [ 3873.067360] Lustre: 4138:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497894/real 1743497894] req@ffff888117e19e40 x1828186618400640/t0(0) o400->MGC192.168.206.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1743497910 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 3873.067539] LustreError: MGC192.168.206.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3893.183576] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 3898.698038] Lustre: Evicted from MGS (at 192.168.206.108@tcp) after server handle changed from 0x0 to 0x242620d573d2e588 [ 3898.701894] Lustre: MGC192.168.206.108@tcp: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 3898.701904] Lustre: Skipped 2 previous similar messages [ 3899.375769] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3899.540858] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3903.728670] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3904.808457] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3904.867447] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:123 to 0x280000401:193) [ 3904.892635] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:123 to 0x2c0000401:193) [ 3913.076005] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 3917.242074] workqueue: delayed_vfree_work hogged CPU for >10000us 259 times, consider switching to WQ_UNBOUND [ 3929.250636] Lustre: Failing over lustre-MDT0001 [ 3929.354444] Lustre: lustre-MDT0001: Not available for connect from 192.168.206.8@tcp (stopping) [ 3929.354488] Lustre: Skipped 2 previous similar messages [ 3929.706662] LDISKFS-fs (dm-1): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [ 3929.768446] Lustre: server umount lustre-MDT0001 complete [ 3929.832369] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3971.254134] LDISKFS-fs (dm-1): mounted filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802 r/w with ordered data mode. Quota mode: journalled. [ 3971.617061] Lustre: 35636:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 3972.463719] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3972.672751] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3974.319551] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3977.535085] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 3977.586599] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:123 to 0x280000400:193) [ 3977.596767] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:123 to 0x2c0000400:193) [ 3984.506412] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 4013.362712] Lustre: DEBUG MARKER: == sanity test 17o: stat file with incompat LMA feature == 05:00:44 (1743498044) [ 4021.884838] Lustre: Failing over lustre-MDT0000 [ 4022.508210] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [ 4022.611932] Lustre: server umount lustre-MDT0000 complete [ 4023.543974] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4023.544028] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4023.544057] Lustre: Skipped 6 previous similar messages [ 4039.381448] Lustre: 4136:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743498061/real 1743498061] req@ffff888113fd9e40 x1828186618486656/t0(0) o400->MGC192.168.206.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1743498077 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4039.381616] LustreError: MGC192.168.206.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4058.967849] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [ 4065.509443] LustreError: 36833:0:(import.c:332:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 4065.509511] LustreError: 36833:0:(import.c:356:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff88811d3c0540 x1828186618495616/t0(0) o250->MGC192.168.206.108@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1743498102 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4065.509542] LustreError: 36833:0:(import.c:365:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 4066.027537] LustreError: 4134:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff88811c737840 x1828186618499968/t0(0) o250->MGC192.168.206.108@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4066.027582] LustreError: 4134:0:(client.c:1292:ptlrpc_import_delay_req()) Skipped 15 previous similar messages [ 4066.492120] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4071.690332] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 4071.690364] Lustre: Skipped 7 previous similar messages [ 4071.796738] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:123 to 0x280000401:225) [ 4071.799185] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:195 to 0x2c0000401:225) [ 4078.063428] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 4097.165547] Lustre: DEBUG MARKER: oleg608-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4101.891991] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4106.970447] Lustre: *** cfs_fail_loc=194, val=0*** [ 4106.974987] Lustre: 9713:0:(osd_handler.c:857:osd_check_lma()) lustre-MDT0000: unsupported incompat LMA feature(s) 0x0 for fid = [0x200000402:0x3af:0x0], ino = 512170 [ 4129.347323] Lustre: DEBUG MARKER: == sanity test 17p: symlink overwrite directory error message ========================================================== 05:02:42 (1743498162) [ 4134.012736] workqueue: srcu_invoke_callbacks hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [ 4149.586018] Lustre: DEBUG MARKER: == sanity test 18: touch .../f ; ls ... ======================================================================================== 05:03:01 (1743498181) [ 4167.486935] Lustre: DEBUG MARKER: == sanity test 19a: touch .../f19 ; ls -l ... ; rm .../f19 ===================================================================== 05:03:19 (1743498199) [ 4187.702585] Lustre: DEBUG MARKER: == sanity test 19b: ls -l .../f19 (should return error) ======================================================================== 05:03:40 (1743498220) [ 4204.079589] Lustre: DEBUG MARKER: == sanity test 19c: runas -u 500 -g 500 touch .../f19 (should return error) ============================================================ 05:03:57 (1743498237) [ 4223.076908] Lustre: DEBUG MARKER: == sanity test 19d: cat .../f19 (should return error) ======================================================================== 05:04:15 (1743498255) [ 4241.442700] Lustre: DEBUG MARKER: == sanity test 20: touch .../f ; ls -l ... =============== 05:04:33 (1743498273) [ 4262.174197] Lustre: DEBUG MARKER: == sanity test 21: write to dangling link ================ 05:04:53 (1743498293) [ 4280.865682] Lustre: DEBUG MARKER: == sanity test 22: unpack tar archive as non-root user === 05:05:13 (1743498313) [ 4300.433990] Lustre: DEBUG MARKER: == sanity test 23a: O_CREAT|O_EXCL in subdir ============= 05:05:32 (1743498332) [ 4319.655204] Lustre: DEBUG MARKER: == sanity test 23b: O_APPEND check ======================= 05:05:52 (1743498352) [ 4338.019098] Lustre: DEBUG MARKER: == sanity test 23c: O_APPEND size checks for tiny writes ========================================================== 05:06:10 (1743498370) [ 4363.484220] Lustre: DEBUG MARKER: == sanity test 23d: file offset is correct after appending writes ========================================================== 05:06:35 (1743498395) [ 4380.643065] Lustre: DEBUG MARKER: == sanity test 24a: rename file to non-existent target === 05:06:53 (1743498413) [ 4398.593349] Lustre: DEBUG MARKER: == sanity test 24b: rename file to existing target ======= 05:07:11 (1743498431) [ 4417.228561] Lustre: DEBUG MARKER: == sanity test 24c: rename directory to non-existent target ========================================================== 05:07:29 (1743498449) [ 4435.684298] Lustre: DEBUG MARKER: == sanity test 24d: rename directory to existing target == 05:07:48 (1743498468) [ 4453.639866] Lustre: DEBUG MARKER: == sanity test 24e: touch .../R5a/f; rename .../R5a/f .../R5b/g ================================================================ 05:08:06 (1743498486) [ 4472.757337] Lustre: DEBUG MARKER: == sanity test 24f: touch .../R6a/f R6b/g; mv .../R6a/f .../R6b/g ============================================================== 05:08:24 (1743498504) [ 4492.464855] Lustre: DEBUG MARKER: == sanity test 24g: mkdir .../R7a/d; .../R7b/d; mv .../R7a/d .../R7b/e ================================================================ 05:08:44 (1743498524) [ 4512.753028] Lustre: DEBUG MARKER: == sanity test 24h: mkdir .../R8a/d; .../R8a/e; .../R8b/d; .../R8b/e; rename .../R8a/d .../R8b/e ========================================================== 05:09:04 (1743498544) [ 4532.257023] Lustre: DEBUG MARKER: == sanity test 24i: rename file to dir error: touch f ; mkdir a ; rename f a ========================================================== 05:09:24 (1743498564) [ 4551.891614] Lustre: DEBUG MARKER: == sanity test 24j: source does not exist ====================================================================================== 05:09:43 (1743498583) [ 4573.764815] Lustre: DEBUG MARKER: == sanity test 24k: touch .../R11a/f; mv .../R11a/f .../R11a/d ================================================================= 05:10:05 (1743498605) [ 4592.340472] Lustre: DEBUG MARKER: == sanity test 24l: Renaming a file to itself ================================================================================== 05:10:25 (1743498625) [ 4609.804763] Lustre: DEBUG MARKER: == sanity test 24m: Renaming a file to a hard link to itself =================================================================== 05:10:42 (1743498642) [ 4627.138921] Lustre: DEBUG MARKER: == sanity test 24n: Statting the old file after renaming (Posix rename 2) ========================================================== 05:10:59 (1743498659) [ 4646.070185] Lustre: DEBUG MARKER: == sanity test 24o: rename of files during htree split === 05:11:18 (1743498678) [ 5547.149474] Lustre: DEBUG MARKER: == sanity test 24p: mkdir .../R12a; .../R12b; rename .../R12a .../R12b ========================================================== 05:26:20 (1743499580) [ 5561.473137] Lustre: DEBUG MARKER: == sanity test 24q: mkdir .../R13a; .../R13b; open R13b rename R13a R13b ============================================================= 05:26:35 (1743499595) [ 5576.445638] Lustre: DEBUG MARKER: == sanity test 24r: mkdir .../R14a/b; rename .../R14a .../R14a/b =============================================================== 05:26:50 (1743499610) [ 5592.042850] Lustre: DEBUG MARKER: == sanity test 24s: mkdir .../R15a/b/c; rename .../R15a .../R15a/b/c =========================================================== 05:27:04 (1743499624) [ 5608.359176] Lustre: DEBUG MARKER: == sanity test 24t: mkdir .../R16a/b/c; rename .../R16a/b/c .../R16a =========================================================== 05:27:21 (1743499641) [ 5624.008927] Lustre: DEBUG MARKER: == sanity test 24u: create stripe file =================== 05:27:37 (1743499657) [ 5639.150988] Lustre: DEBUG MARKER: == sanity test 24v: list large directory (test hash collision, b=17560) ========================================================== 05:27:52 (1743499672) [ 6094.158253] workqueue: rht_deferred_worker hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [ 6531.319259] workqueue: rht_deferred_worker hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND [ 7478.815255] workqueue: rht_deferred_worker hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 7817.878427] Lustre: DEBUG MARKER: == sanity test 24w: Reading a file larger than 4Gb ======= 06:04:12 (1743501852) [ 7827.968928] Lustre: DEBUG MARKER: == sanity test 24x: cross MDT rename/link ================ 06:04:22 (1743501862) [ 7839.008034] Lustre: DEBUG MARKER: == sanity test 24y: rename/link on the same dir should succeed ========================================================== 06:04:33 (1743501873) [ 7850.140061] Lustre: DEBUG MARKER: == sanity test 24z: cross-MDT rename is done as cp ======= 06:04:44 (1743501884) [ 7864.031850] Lustre: DEBUG MARKER: == sanity test 24A: readdir() returns correct number of entries. ========================================================== 06:04:58 (1743501898) [ 7949.770301] Lustre: DEBUG MARKER: == sanity test 24B: readdir for striped dir return correct number of entries ========================================================== 06:06:24 (1743501984) [ 7960.168500] Lustre: DEBUG MARKER: == sanity test 24C: check .. in striped dir ============== 06:06:34 (1743501994) [ 7971.054163] Lustre: DEBUG MARKER: == sanity test 24E: cross MDT rename/link ================ 06:06:45 (1743502005) [ 7973.389113] Lustre: DEBUG MARKER: SKIP: sanity test_24E needs >= 4 MDTs [ 7976.031734] Lustre: DEBUG MARKER: == sanity test 24F: hash order vs readdir (LU-11330) ===== 06:06:50 (1743502010) [ 8019.499777] Lustre: DEBUG MARKER: == sanity test 24G: migrate symlink in rename ============ 06:07:33 (1743502053) [ 8030.349273] Lustre: DEBUG MARKER: == sanity test 24H: repeat FLD_QUERY rpc ================= 06:07:44 (1743502064) [ 8042.011820] Lustre: DEBUG MARKER: == sanity test 25a: create file in symlinked directory ========================================================================= 06:07:56 (1743502076) [ 8052.028047] Lustre: DEBUG MARKER: == sanity test 25b: lookup file in symlinked directory ========================================================================= 06:08:06 (1743502086) [ 8061.604649] Lustre: DEBUG MARKER: == sanity test 26a: multiple component symlink ================================================================================= 06:08:16 (1743502096) [ 8071.293368] Lustre: DEBUG MARKER: == sanity test 26b: multiple component symlink at end of lookup ================================================================ 06:08:25 (1743502105) [ 8081.049649] Lustre: DEBUG MARKER: == sanity test 26c: chain of symlinks ==================== 06:08:35 (1743502115) [ 8091.148207] Lustre: DEBUG MARKER: == sanity test 26d: create multiple component recursive symlink ========================================================== 06:08:45 (1743502125) [ 8100.949535] Lustre: DEBUG MARKER: == sanity test 26e: unlink multiple component recursive symlink ========================================================== 06:08:55 (1743502135) [ 8110.890585] Lustre: DEBUG MARKER: == sanity test 26f: rm -r of a directory which has recursive symlink ========================================================== 06:09:05 (1743502145) [ 8122.538485] Lustre: DEBUG MARKER: == sanity test 27a: one stripe file ====================== 06:09:16 (1743502156) [ 8132.618451] Lustre: DEBUG MARKER: == sanity test 27b: create and write to two stripe file == 06:09:27 (1743502167) [ 8142.883097] Lustre: DEBUG MARKER: == sanity test 27ca: one stripe on specified OST ========= 06:09:37 (1743502177) [ 8153.958478] Lustre: DEBUG MARKER: == sanity test 27cb: two stripes on specified OSTs ======= 06:09:48 (1743502188) [ 8164.929566] Lustre: DEBUG MARKER: == sanity test 27cc: two stripes on the same OST ========= 06:09:59 (1743502199) [ 8176.079865] Lustre: DEBUG MARKER: == sanity test 27cd: four stripes on two OSTs ============ 06:10:10 (1743502210) [ 8186.033252] workqueue: drain_vmap_area_work hogged CPU for >10000us 11 times, consider switching to WQ_UNBOUND [ 8187.258339] Lustre: DEBUG MARKER: == sanity test 27ce: more stripes than OSTs with -o ====== 06:10:21 (1743502221) [ 8198.321929] Lustre: DEBUG MARKER: == sanity test 27cf: 'setstripe -o' on inactive OSTs should return error ========================================================== 06:10:32 (1743502232) [ 8200.034476] Lustre: setting import lustre-OST0000_UUID INACTIVE by administrator request [ 8204.423007] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 8204.423066] Lustre: Skipped 3 previous similar messages [ 8204.424683] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 8204.425670] LustreError: lustre-OST0000-osc-MDT0000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 8204.426685] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 8204.426693] Lustre: Skipped 3 previous similar messages [ 8204.429967] LustreError: lustre-OST0000-osc-MDT0001: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 8217.882892] Lustre: DEBUG MARKER: == sanity test 27cg: 1000 shouldn't cause too many credits ========================================================== 06:10:52 (1743502252) [ 8224.185874] Lustre: 7507:0:(osd_handler.c:2067:osd_trans_start()) lustre-MDT0000: credits 30372 > trans_max 3200 [ 8224.185925] Lustre: 7507:0:(osd_handler.c:1961:osd_trans_dump_creds()) create: 4/16/0, destroy: 1/4/0 [ 8224.185964] Lustre: 7507:0:(osd_handler.c:1968:osd_trans_dump_creds()) attr_set: 2003/2003/0, xattr_set: 3004/28148/0 [ 8224.185978] Lustre: 7507:0:(osd_handler.c:1975:osd_trans_dump_creds()) write: 20/109/0, punch: 0/0/0, quota 0/0/0 [ 8224.185988] Lustre: 7507:0:(osd_handler.c:1985:osd_trans_dump_creds()) insert: 5/84/0, delete: 2/5/0 [ 8224.185997] Lustre: 7507:0:(osd_handler.c:1992:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/0 [ 8224.186006] CPU: 1 PID: 7507 Comm: mdt00_002 Kdump: loaded Tainted: G W OE ------- --- 5.14.0rocky95-debug #3 [ 8224.186014] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 8224.186018] Call Trace: [ 8224.186023] [ 8224.186032] dump_stack_lvl+0x41/0x5e [ 8224.186069] osd_trans_start+0x120d/0x1920 [osd_ldiskfs] [ 8224.186149] ? mdd_migrate_sanity_check.constprop.0+0x900/0x900 [mdd] [ 8224.186231] top_trans_start+0x661/0xe40 [ptlrpc] [ 8224.186670] mdd_unlink+0x7f0/0x2000 [mdd] [ 8224.186749] mdt_reint_unlink+0x1cee/0x4080 [mdt] [ 8224.187043] mdt_reint_rec+0x268/0x610 [mdt] [ 8224.187183] mdt_reint_internal+0x924/0x1280 [mdt] [ 8224.187319] ? tsi2mdt_info+0x9b/0x370 [mdt] [ 8224.187452] mdt_reint+0xf5/0x2a0 [mdt] [ 8224.187593] tgt_handle_request0+0x281/0x1360 [ptlrpc] [ 8224.188033] tgt_request_handle+0x716/0x1e50 [ptlrpc] [ 8224.188432] ? tgt_blocking_ast+0x10a0/0x10a0 [ptlrpc] [ 8224.188850] ptlrpc_server_handle_request.isra.0+0xa07/0x2220 [ptlrpc] [ 8224.189252] ptlrpc_main+0x1a2d/0x2da0 [ptlrpc] [ 8224.189643] ? __kthread_parkme+0xc7/0x200 [ 8224.189655] ? ptlrpc_watchdog_init+0x1d0/0x1d0 [ptlrpc] [ 8224.190054] kthread+0x2ab/0x350 [ 8224.190062] ? kthread_insert_work_sanity_check+0xd0/0xd0 [ 8224.190069] ret_from_fork+0x1f/0x30 [ 8224.190085] [ 8238.582267] Lustre: DEBUG MARKER: == sanity test 27d: create file with default settings ==== 06:11:11 (1743502271) [ 8248.968626] Lustre: DEBUG MARKER: == sanity test 27e: setstripe existing file (should return error) ========================================================== 06:11:23 (1743502283) [ 8259.490821] Lustre: DEBUG MARKER: == sanity test 27f: setstripe with bad stripe size (should return error) ========================================================== 06:11:33 (1743502293) [ 8270.064798] Lustre: DEBUG MARKER: == sanity test 27g: /home/green/git/lustre-release/lustre/utils/lfs getstripe with no objects ========================================================== 06:11:44 (1743502304) [ 8280.329806] Lustre: DEBUG MARKER: == sanity test 27ga: /home/green/git/lustre-release/lustre/utils/lfs getstripe with missing file (should return error) ========================================================== 06:11:54 (1743502314) [ 8290.543592] Lustre: DEBUG MARKER: == sanity test 27i: /home/green/git/lustre-release/lustre/utils/lfs getstripe with some objects ========================================================== 06:12:04 (1743502324) [ 8300.657822] Lustre: DEBUG MARKER: == sanity test 27j: setstripe with bad stripe offset (should return error) ========================================================== 06:12:15 (1743502335) [ 8310.457176] Lustre: DEBUG MARKER: == sanity test 27k: limit i_blksize for broken user apps ========================================================== 06:12:24 (1743502344) [ 8321.107999] Lustre: DEBUG MARKER: == sanity test 27l: check setstripe permissions (should return error) ========================================================== 06:12:35 (1743502355) [ 8331.543579] Lustre: DEBUG MARKER: SKIP: sanity test_27m skipping SLOW test 27m [ 8334.270565] Lustre: DEBUG MARKER: == sanity test 27n: create file with some full OSTs ====== 06:12:48 (1743502368) [ 8352.998605] Lustre: *** cfs_fail_loc=215, val=0*** [ 8358.118731] Lustre: *** cfs_fail_loc=215, val=0*** [ 8358.118780] Lustre: Skipped 1 previous similar message [ 8387.312420] Lustre: DEBUG MARKER: == sanity test 27o: create file with all full OSTs (should error) ========================================================== 06:13:41 (1743502421) [ 8403.686494] Lustre: *** cfs_fail_loc=215, val=1*** [ 8405.363125] LustreError: 7505:0:(lod_qos.c:1378:lod_ost_alloc_specific()) can't lstripe objid [0x200000402:0xd22e:0x0]: have 0 want 1 [ 8406.758559] Lustre: *** cfs_fail_loc=215, val=1*** [ 8406.758587] Lustre: Skipped 2 previous similar messages [ 8411.879226] Lustre: *** cfs_fail_loc=215, val=1*** [ 8411.881376] Lustre: Skipped 3 previous similar messages [ 8414.773819] LustreError: 19396:0:(lod_qos.c:1378:lod_ost_alloc_specific()) can't lstripe objid [0x200000402:0xd232:0x0]: have 0 want 1 [ 8422.118657] Lustre: *** cfs_fail_loc=215, val=1*** [ 8422.118688] Lustre: Skipped 7 previous similar messages [ 8449.184202] Lustre: DEBUG MARKER: == sanity test 27oo: don't let few threads to reserve too many objects ========================================================== 06:14:43 (1743502483) [ 8473.158978] Lustre: Failing over lustre-OST0000 [ 8473.321565] LDISKFS-fs (dm-2): unmounting filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f. [ 8473.356864] Lustre: server umount lustre-OST0000 complete [ 8474.857832] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 8474.857873] Lustre: Skipped 1 previous similar message [ 8474.860662] LustreError: 53662:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8474.860681] LustreError: 53662:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 177 previous similar messages [ 8477.025752] ODEBUG: object ffffc9000e0f7028 is on stack ffffc9000e0f0000, but NOT annotated. [ 8477.025815] ------------[ cut here ]------------ [ 8477.025820] WARNING: CPU: 2 PID: 9970 at lib/debugobjects.c:557 lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.025874] Modules linked in: zfs(O) spl(O) lustre(OE) osp(OE) ofd(OE) lod(OE) mdt(OE) mdd(OE) mgs(OE) osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) lfsck(OE) obdecho(OE) mgc(OE) mdc(OE) lov(OE) osc(OE) lmv(OE) fid(OE) fld(OE) ptlrpc_gss(OE) ptlrpc(OE) obdclass(OE) ksocklnd(OE) lnet(OE) libcfs(OE) dm_flakey rfkill rpcsec_gss_krb5 auth_rpcgss intel_rapl_msr intel_rapl_common kvm_intel kvm rapl i2c_piix4 pcspkr joydev squashfs drm fuse ext4 mbcache jbd2 crct10dif_pclmul crc32_pclmul crc32c_intel ata_generic ata_piix ghash_clmulni_intel libata serio_raw dm_mirror dm_region_hash dm_log dm_mod [ 8477.026006] CPU: 2 PID: 9970 Comm: mdt00_004 Kdump: loaded Tainted: G W OE ------- --- 5.14.0rocky95-debug #3 [ 8477.026014] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 8477.026019] RIP: 0010:lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.026027] Code: 2a 44 89 2d 74 ac 56 04 48 c1 ea 03 80 3c 02 00 74 05 e8 95 6a 38 fe 48 8b 53 28 48 89 ee 48 c7 c7 c0 98 7a b6 e8 b9 14 fc ff <0f> 0b e9 47 65 bf fe 65 48 8b 1c 25 c0 51 20 00 48 8d 7b 28 b8 ff [ 8477.026033] RSP: 0018:ffffc9000e0f6db8 EFLAGS: 00010086 [ 8477.026040] RAX: 0000000000000050 RBX: ffff88810e1f8040 RCX: 0000000000000000 [ 8477.026044] RDX: 0000000000000002 RSI: ffffffffb67a8ae0 RDI: fffff52001c1edaa [ 8477.026048] RBP: ffffc9000e0f7028 R08: 0000000000000050 R09: ffffed1023fffd88 [ 8477.026052] R10: ffff88811fffec47 R11: 0000000000000007 R12: ffff88802a244cc0 [ 8477.026056] R13: 0000000000000001 R14: ffff88810e1f8040 R15: ffffffffba711b70 [ 8477.026060] FS: 0000000000000000(0000) GS:ffff88811fe00000(0000) knlGS:0000000000000000 [ 8477.026071] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 8477.026076] CR2: 000055c4ec78b7f8 CR3: 0000000111891003 CR4: 0000000000170ef0 [ 8477.026081] Call Trace: [ 8477.026086] [ 8477.026093] ? show_trace_log_lvl+0x1c4/0x2db [ 8477.026104] ? show_trace_log_lvl+0x1c4/0x2db [ 8477.026117] ? __debug_object_init+0x124/0x2a0 [ 8477.026128] ? lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.026135] ? __warn+0xce/0x180 [ 8477.026144] ? lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.026151] ? report_bug+0x1eb/0x360 [ 8477.026165] ? handle_bug+0x3c/0x70 [ 8477.026175] ? exc_invalid_op+0x14/0x40 [ 8477.026181] ? asm_exc_invalid_op+0x16/0x20 [ 8477.026195] ? lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.026202] ? lookup_object_or_alloc.part.0.cold+0x93/0x95 [ 8477.026211] __debug_object_init+0x124/0x2a0 [ 8477.026220] ? lod_obj_is_ost_use_cb+0x180/0x180 [lod] [ 8477.026294] init_timer_key+0x2e/0x2c0 [ 8477.026307] lod_ost_alloc_qos+0x651/0x2e20 [lod] [ 8477.026392] ? libcfs_debug_msg+0x15a5/0x20b0 [libcfs] [ 8477.026415] ? mdt_reint_open+0x4447/0x6710 [mdt] [ 8477.026516] ? mdt_reint_internal+0x924/0x1280 [mdt] [ 8477.026579] ? mdt_intent_open+0x27f/0xb30 [mdt] [ 8477.026666] ? lod_ost_alloc_rr+0x1640/0x1640 [lod] [ 8477.026715] ? cfs_trace_put_tcd+0xe0/0xe0 [libcfs] [ 8477.026733] ? trace_contention_begin+0x200/0x200 [ 8477.026740] ? lod_qos_prep_create+0x77e/0x1bb0 [lod] [ 8477.026812] ? lock_release+0x70/0x330 [ 8477.026826] ? rwsem_down_read_slowpath+0xb60/0xb60 [ 8477.026838] lod_qos_prep_create+0x124a/0x1bb0 [lod] [ 8477.026891] ? lod_qos_parse_config+0x2730/0x2730 [lod] [ 8477.026941] lod_prepare_create+0x5a4/0x910 [lod] [ 8477.026991] lod_declare_striped_create+0x29f/0x960 [lod] [ 8477.027049] lod_declare_create+0x2c6/0x15d0 [lod] [ 8477.027125] ? libcfs_debug_msg+0x15a5/0x20b0 [libcfs] [ 8477.027159] ? lod_dir_striping_create_internal+0x1da0/0x1da0 [lod] [ 8477.027241] mdd_declare_create_object_internal+0x2a2/0x800 [mdd] [ 8477.027319] mdd_declare_create_object.constprop.0+0xb1/0x1190 [mdd] [ 8477.027383] mdd_declare_create+0x69/0x8d0 [mdd] [ 8477.027450] mdd_create+0x79c/0x2320 [mdd] [ 8477.027522] ? mdd_link+0x1ef0/0x1ef0 [mdd] [ 8477.027604] mdt_reint_open+0x4447/0x6710 [mdt] [ 8477.027734] ? mdt_cross_open.constprop.0+0x12b0/0x12b0 [mdt] [ 8477.027852] mdt_reint_rec+0x268/0x610 [mdt] [ 8477.027970] mdt_reint_internal+0x924/0x1280 [mdt] [ 8477.028081] ? mdt_intent_fixup_resent+0x8b/0x5b0 [mdt] [ 8477.028192] mdt_intent_open+0x27f/0xb30 [mdt] [ 8477.028305] ? mdt_intent_fixup_resent+0x5b0/0x5b0 [mdt] [ 8477.028414] mdt_intent_opc.constprop.0+0x242/0xee0 [mdt] [ 8477.028531] mdt_intent_policy+0x29c/0xa80 [mdt] [ 8477.028661] ldlm_lock_enqueue+0x9f3/0x15d0 [ptlrpc] [ 8477.029062] ? do_raw_read_unlock+0x40/0x70 [ 8477.029073] ? ldlm_handle_conflict_lock+0x790/0x790 [ptlrpc] [ 8477.029418] ? cfs_hash_rehash+0x6d0/0x6d0 [obdclass] [ 8477.029611] ldlm_handle_enqueue+0xa8f/0x3ec0 [ptlrpc] [ 8477.029896] ? lustre_swab_ldlm_lock_desc+0x220/0x220 [ptlrpc] [ 8477.030219] ? ldlm_server_completion_ast+0x1620/0x1620 [ptlrpc] [ 8477.030458] ? __req_capsule_get+0x24c/0x7a0 [ptlrpc] [ 8477.030795] tgt_enqueue+0x17e/0x5b0 [ptlrpc] [ 8477.031124] tgt_handle_request0+0x281/0x1360 [ptlrpc] [ 8477.031475] tgt_request_handle+0x716/0x1e50 [ptlrpc] [ 8477.031859] ? tgt_blocking_ast+0x10a0/0x10a0 [ptlrpc] [ 8477.032251] ptlrpc_server_handle_request.isra.0+0xa07/0x2220 [ptlrpc] [ 8477.032619] ptlrpc_main+0x1a2d/0x2da0 [ptlrpc] [ 8477.032980] ? __kthread_parkme+0xc7/0x200 [ 8477.032990] ? ptlrpc_watchdog_init+0x1d0/0x1d0 [ptlrpc] [ 8477.033387] kthread+0x2ab/0x350 [ 8477.033395] ? kthread_insert_work_sanity_check+0xd0/0xd0 [ 8477.033404] ret_from_fork+0x1f/0x30 [ 8477.033420] [ 8477.033424] ---[ end trace 0000000000000000 ]--- [ 8477.065044] ODEBUG: object ffffc9000373f028 is on stack ffffc90003738000, but NOT annotated. [ 8477.065106] ------------[ cut here ]------------ [ 8477.065112] WARNING: CPU: 0 PID: 19396 at lib/debugobjects.c:557 lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.065128] Modules linked in: zfs(O) spl(O) lustre(OE) osp(OE) ofd(OE) lod(OE) mdt(OE) mdd(OE) mgs(OE) osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) lfsck(OE) obdecho(OE) mgc(OE) mdc(OE) lov(OE) osc(OE) lmv(OE) fid(OE) fld(OE) ptlrpc_gss(OE) ptlrpc(OE) obdclass(OE) ksocklnd(OE) lnet(OE) libcfs(OE) dm_flakey rfkill rpcsec_gss_krb5 auth_rpcgss intel_rapl_msr intel_rapl_common kvm_intel kvm rapl i2c_piix4 pcspkr joydev squashfs drm fuse ext4 mbcache jbd2 crct10dif_pclmul crc32_pclmul crc32c_intel ata_generic ata_piix ghash_clmulni_intel libata serio_raw dm_mirror dm_region_hash dm_log dm_mod [ 8477.065265] CPU: 0 PID: 19396 Comm: mdt00_005 Kdump: loaded Tainted: G W OE ------- --- 5.14.0rocky95-debug #3 [ 8477.065274] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 8477.065280] RIP: 0010:lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.065289] Code: 2a 44 89 2d 74 ac 56 04 48 c1 ea 03 80 3c 02 00 74 05 e8 95 6a 38 fe 48 8b 53 28 48 89 ee 48 c7 c7 c0 98 7a b6 e8 b9 14 fc ff <0f> 0b e9 47 65 bf fe 65 48 8b 1c 25 c0 51 20 00 48 8d 7b 28 b8 ff [ 8477.065296] RSP: 0018:ffffc9000373edb8 EFLAGS: 00010086 [ 8477.065303] RAX: 0000000000000050 RBX: ffff888038d88040 RCX: 0000000000000000 [ 8477.065308] RDX: 0000000000000002 RSI: ffffffffb67a8ae0 RDI: fffff520006e7daa [ 8477.065313] RBP: ffffc9000373f028 R08: 0000000000000050 R09: ffffed1023effd88 [ 8477.065318] R10: ffff88811f7fec47 R11: 0000000000000007 R12: ffff888029093f80 [ 8477.065323] R13: 0000000000000002 R14: ffff888038d88040 R15: ffffffffba63ec20 [ 8477.065328] FS: 0000000000000000(0000) GS:ffff88811f600000(0000) knlGS:0000000000000000 [ 8477.065339] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 8477.065344] CR2: 00007f744b14e0f0 CR3: 0000000105008006 CR4: 0000000000170ef0 [ 8477.065349] Call Trace: [ 8477.065353] [ 8477.065360] ? show_trace_log_lvl+0x1c4/0x2db [ 8477.065372] ? show_trace_log_lvl+0x1c4/0x2db [ 8477.065386] ? __debug_object_init+0x124/0x2a0 [ 8477.065397] ? lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.065404] ? __warn+0xce/0x180 [ 8477.065414] ? lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.065422] ? report_bug+0x1eb/0x360 [ 8477.065438] ? handle_bug+0x3c/0x70 [ 8477.065449] ? exc_invalid_op+0x14/0x40 [ 8477.065457] ? asm_exc_invalid_op+0x16/0x20 [ 8477.065471] ? lookup_object_or_alloc.part.0.cold+0x46/0x95 [ 8477.065479] ? lookup_object_or_alloc.part.0.cold+0x93/0x95 [ 8477.065487] __debug_object_init+0x124/0x2a0 [ 8477.065497] ? lod_obj_is_ost_use_cb+0x180/0x180 [lod] [ 8477.065603] init_timer_key+0x2e/0x2c0 [ 8477.065618] lod_ost_alloc_qos+0x651/0x2e20 [lod] [ 8477.065712] ? libcfs_debug_msg+0x15a5/0x20b0 [libcfs] [ 8477.065749] ? mdt_reint_open+0x4447/0x6710 [mdt] [ 8477.065888] ? mdt_reint_internal+0x924/0x1280 [mdt] [ 8477.066012] ? mdt_intent_open+0x27f/0xb30 [mdt] [ 8477.066148] ? lod_ost_alloc_rr+0x1640/0x1640 [lod] [ 8477.066238] ? cfs_trace_put_tcd+0xe0/0xe0 [libcfs] [ 8477.066274] ? trace_contention_begin+0x200/0x200 [ 8477.066285] ? lod_qos_prep_create+0x77e/0x1bb0 [lod] [ 8477.066378] ? lock_release+0x70/0x330 [ 8477.066393] ? rwsem_down_read_slowpath+0xb60/0xb60 [ 8477.066409] lod_qos_prep_create+0x124a/0x1bb0 [lod] [ 8477.066512] ? lod_qos_parse_config+0x2730/0x2730 [lod] [ 8477.066624] lod_prepare_create+0x5a4/0x910 [lod] [ 8477.066726] lod_declare_striped_create+0x29f/0x960 [lod] [ 8477.066825] lod_declare_create+0x2c6/0x15d0 [lod] [ 8477.066926] ? libcfs_debug_msg+0x15a5/0x20b0 [libcfs] [ 8477.066965] ? lod_dir_striping_create_internal+0x1da0/0x1da0 [lod] [ 8477.067067] mdd_declare_create_object_internal+0x2a2/0x800 [mdd] [ 8477.067154] mdd_declare_create_object.constprop.0+0xb1/0x1190 [mdd] [ 8477.067229] mdd_declare_create+0x69/0x8d0 [mdd] [ 8477.067307] mdd_create+0x79c/0x2320 [mdd] [ 8477.067393] ? mdd_link+0x1ef0/0x1ef0 [mdd] [ 8477.067478] mdt_reint_open+0x4447/0x6710 [mdt] [ 8477.067649] ? mdt_cross_open.constprop.0+0x12b0/0x12b0 [mdt] [ 8477.067795] mdt_reint_rec+0x268/0x610 [mdt] [ 8477.067938] mdt_reint_internal+0x924/0x1280 [mdt] [ 8477.068085] ? mdt_intent_fixup_resent+0x8b/0x5b0 [mdt] [ 8477.068215] mdt_intent_open+0x27f/0xb30 [mdt] [ 8477.068362] ? mdt_intent_fixup_resent+0x5b0/0x5b0 [mdt] [ 8477.068500] mdt_intent_opc.constprop.0+0x242/0xee0 [mdt] [ 8477.068658] mdt_intent_policy+0x29c/0xa80 [mdt] [ 8477.068806] ldlm_lock_enqueue+0x9f3/0x15d0 [ptlrpc] [ 8477.069256] ? do_raw_read_unlock+0x40/0x70 [ 8477.069269] ? ldlm_handle_conflict_lock+0x790/0x790 [ptlrpc] [ 8477.069708] ? cfs_hash_rehash+0x6d0/0x6d0 [obdclass] [ 8477.069991] ldlm_handle_enqueue+0xa8f/0x3ec0 [ptlrpc] [ 8477.070446] ? lustre_swab_ldlm_lock_desc+0x220/0x220 [ptlrpc] [ 8477.070904] ? ldlm_server_completion_ast+0x1620/0x1620 [ptlrpc] [ 8477.071335] ? __req_capsule_get+0x24c/0x7a0 [ptlrpc] [ 8477.071802] tgt_enqueue+0x17e/0x5b0 [ptlrpc] [ 8477.072222] tgt_handle_request0+0x281/0x1360 [ptlrpc] [ 8477.072664] tgt_request_handle+0x716/0x1e50 [ptlrpc] [ 8477.073105] ? tgt_blocking_ast+0x10a0/0x10a0 [ptlrpc] [ 8477.073543] ptlrpc_server_handle_request.isra.0+0xa07/0x2220 [ptlrpc] [ 8477.073973] ptlrpc_main+0x1a2d/0x2da0 [ptlrpc] [ 8477.074373] ? __kthread_parkme+0xc7/0x200 [ 8477.074384] ? ptlrpc_watchdog_init+0x1d0/0x1d0 [ptlrpc] [ 8477.074779] kthread+0x2ab/0x350 [ 8477.074788] ? kthread_insert_work_sanity_check+0xd0/0xd0 [ 8477.074797] ret_from_fork+0x1f/0x30 [ 8477.074814] [ 8477.074819] ---[ end trace 0000000000000000 ]--- [ 8494.400054] LDISKFS-fs (dm-2): mounted filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f r/w with ordered data mode. Quota mode: journalled. [ 8494.515554] Lustre: 59728:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 8494.715907] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 8494.725898] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 8494.725919] Lustre: Skipped 1 previous similar message [ 8496.591961] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 8496.592001] Lustre: Skipped 1 previous similar message [ 8496.629218] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 8496.629276] Lustre: Skipped 1 previous similar message [ 8496.629460] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 8496.629468] Lustre: Skipped 1 previous similar message [ 8502.799115] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 8510.699990] Lustre: DEBUG MARKER: == sanity test 27p: append to a truncated file with some full OSTs ========================================================== 06:15:45 (1743502545) [ 8537.830454] Lustre: *** cfs_fail_loc=215, val=0*** [ 8537.830481] Lustre: Skipped 7 previous similar messages [ 8575.939539] Lustre: DEBUG MARKER: == sanity test 27q: append to truncated file with all OSTs full (should error) ========================================================== 06:16:50 (1743502610) [ 8591.078432] Lustre: *** cfs_fail_loc=215, val=1*** [ 8591.078460] Lustre: Skipped 4 previous similar messages [ 8602.505149] LustreError: 9713:0:(lod_qos.c:1378:lod_ost_alloc_specific()) can't lstripe objid [0x200000402:0xd269:0x0]: have 0 want 1 [ 8636.746452] Lustre: DEBUG MARKER: == sanity test 27r: stripe file with some full OSTs (shouldn't LBUG) =========================================================== 06:17:51 (1743502671) [ 8655.590185] Lustre: *** cfs_fail_loc=215, val=0*** [ 8655.590225] Lustre: Skipped 23 previous similar messages [ 8686.563322] Lustre: DEBUG MARKER: == sanity test 27s: lsm_xfersize overflow (should error) (bug 10725) ========================================================== 06:18:41 (1743502721) [ 8696.023080] Lustre: DEBUG MARKER: == sanity test 27t: check that utils parse path correctly ========================================================== 06:18:50 (1743502730) [ 8705.703727] Lustre: DEBUG MARKER: == sanity test 27u: skip object creation on OSC w/o objects ========================================================== 06:19:00 (1743502740) [ 8711.408130] Lustre: *** cfs_fail_loc=139, val=0*** [ 8711.911613] Lustre: *** cfs_fail_loc=139, val=0*** [ 8711.911644] Lustre: Skipped 144 previous similar messages [ 8712.918043] Lustre: *** cfs_fail_loc=139, val=0*** [ 8712.918077] Lustre: Skipped 307 previous similar messages [ 8714.923827] Lustre: *** cfs_fail_loc=139, val=0*** [ 8714.923856] Lustre: Skipped 557 previous similar messages [ 8763.975517] Lustre: DEBUG MARKER: == sanity test 27v: skip object creation on slow OST ===== 06:19:58 (1743502798) [ 8778.993038] LustreError: 7506:0:(lod_qos.c:1378:lod_ost_alloc_specific()) can't lstripe objid [0x200000402:0xd4a8:0x0]: have 0 want 1 [ 8783.590601] Lustre: *** cfs_fail_loc=215, val=0*** [ 8783.590633] Lustre: Skipped 14 previous similar messages [ 8833.809136] Lustre: DEBUG MARKER: == sanity test 27w: check /home/green/git/lustre-release/lustre/utils/lfs setstripe -S and getstrip -d options ========================================================== 06:21:08 (1743502868) [ 8843.128736] Lustre: DEBUG MARKER: == sanity test 27wa: check /home/green/git/lustre-release/lustre/utils/lfs setstripe -c -i options ========================================================== 06:21:17 (1743502877) [ 8852.713658] Lustre: DEBUG MARKER: == sanity test 27x: create files while OST0 is degraded == 06:21:27 (1743502887) [ 8877.108262] Lustre: DEBUG MARKER: == sanity test 27y: create files while OST0 is degraded and the rest inactive ========================================================== 06:21:51 (1743502911) [ 8883.584137] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 8883.584166] Lustre: Skipped 1 previous similar message [ 8885.010686] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 8904.155018] Lustre: lustre-OST0001-osc-MDT0001: Connection to lustre-OST0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 8904.155079] Lustre: Skipped 1 previous similar message [ 8904.156591] Lustre: lustre-OST0001: Client lustre-MDT0001-mdtlov_UUID (at 0@lo) reconnecting [ 8904.156601] Lustre: Skipped 1 previous similar message [ 8904.157447] LustreError: lustre-OST0001-osc-MDT0001: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 8904.158282] Lustre: lustre-OST0001-osc-MDT0001: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 8904.158290] Lustre: Skipped 1 previous similar message [ 8905.596008] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 8905.596656] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 8926.904936] Lustre: DEBUG MARKER: == sanity test 27z: check SEQ/OID on the MDT and OST filesystems ========================================================== 06:22:41 (1743502961) [ 8935.329506] Lustre: DEBUG MARKER: check file /mnt/lustre/d27z.sanity/f27z.sanity-1 [ 8937.772340] Lustre: DEBUG MARKER: FID seq 0x200000402, oid 0xd4d3 ver 0x0 [ 8940.135606] Lustre: DEBUG MARKER: LOV seq 0x200000402, oid 0xd4d3, count: 1 [ 8942.631191] Lustre: DEBUG MARKER: want: stripe:0 ost:0 oid:889/0x379 seq:0x280000401 [ 8946.498224] Lustre: DEBUG MARKER: check file /mnt/lustre/d27z.sanity/f27z.sanity-2 [ 8949.155051] Lustre: DEBUG MARKER: FID seq 0x240000402, oid 0xfb00 ver 0x0 [ 8951.499985] Lustre: DEBUG MARKER: LOV seq 0x240000402, oid 0xfb00, count: 2 [ 8954.141803] Lustre: DEBUG MARKER: want: stripe:0 ost:1 oid:755/0x2f3 seq:0x2c0000400 [ 8958.346752] Lustre: DEBUG MARKER: want: stripe:1 ost:0 oid:214/0xd6 seq:0x280000400 [ 8970.245148] Lustre: DEBUG MARKER: == sanity test 27A: check filesystem-wide default LOV EA values ========================================================== 06:23:24 (1743503004) [ 8981.245852] Lustre: DEBUG MARKER: == sanity test 27B: call setstripe on open unlinked file/rename victim ========================================================== 06:23:35 (1743503015) [ 8991.418737] Lustre: DEBUG MARKER: == sanity test 27Ca: check full striping across all OSTs ========================================================== 06:23:45 (1743503025) [ 9001.493115] Lustre: DEBUG MARKER: == sanity test 27Cb: more stripes than OSTs with -C ====== 06:23:55 (1743503035) [ 9012.120998] Lustre: DEBUG MARKER: == sanity test 27Cc: fewer stripes than OSTs does not set overstriping ========================================================== 06:24:06 (1743503046) [ 9022.140503] Lustre: DEBUG MARKER: == sanity test 27Cd: test maximum stripe count =========== 06:24:16 (1743503056) [ 9031.137732] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x2c0000401 to 0x2c0000402 [ 9031.556707] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x280000401 to 0x280000402 [ 9031.612293] Lustre: lustre-OST0000-osc-MDT0001: update sequence from 0x280000400 to 0x280000403 [ 9031.676510] Lustre: lustre-OST0001-osc-MDT0001: update sequence from 0x2c0000400 to 0x2c0000403 [ 9051.582059] Lustre: 72237:0:(osd_handler.c:2067:osd_trans_start()) lustre-MDT0001: credits 60372 > trans_max 3200 [ 9051.582113] Lustre: 72237:0:(osd_handler.c:1961:osd_trans_dump_creds()) create: 4/16/0, destroy: 1/4/0 [ 9051.582150] Lustre: 72237:0:(osd_handler.c:1968:osd_trans_dump_creds()) attr_set: 4003/4003/0, xattr_set: 6004/56148/0 [ 9051.582165] Lustre: 72237:0:(osd_handler.c:1975:osd_trans_dump_creds()) write: 20/109/0, punch: 0/0/0, quota 0/0/0 [ 9051.582176] Lustre: 72237:0:(osd_handler.c:1985:osd_trans_dump_creds()) insert: 5/84/0, delete: 2/5/0 [ 9051.582184] Lustre: 72237:0:(osd_handler.c:1992:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/0 [ 9051.582192] CPU: 0 PID: 72237 Comm: mdt00_006 Kdump: loaded Tainted: G W OE ------- --- 5.14.0rocky95-debug #3 [ 9051.582199] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 9051.582204] Call Trace: [ 9051.582209] [ 9051.582218] dump_stack_lvl+0x41/0x5e [ 9051.582268] osd_trans_start+0x120d/0x1920 [osd_ldiskfs] [ 9051.582345] ? mdd_migrate_sanity_check.constprop.0+0x900/0x900 [mdd] [ 9051.582423] top_trans_start+0x661/0xe40 [ptlrpc] [ 9051.582851] mdd_unlink+0x7f0/0x2000 [mdd] [ 9051.582924] mdt_reint_unlink+0x1cee/0x4080 [mdt] [ 9051.583053] mdt_reint_rec+0x268/0x610 [mdt] [ 9051.583167] mdt_reint_internal+0x924/0x1280 [mdt] [ 9051.583273] ? tsi2mdt_info+0x9b/0x370 [mdt] [ 9051.583386] mdt_reint+0xf5/0x2a0 [mdt] [ 9051.583509] tgt_handle_request0+0x281/0x1360 [ptlrpc] [ 9051.583871] tgt_request_handle+0x716/0x1e50 [ptlrpc] [ 9051.584208] ? tgt_blocking_ast+0x10a0/0x10a0 [ptlrpc] [ 9051.584552] ptlrpc_server_handle_request.isra.0+0xa07/0x2220 [ptlrpc] [ 9051.584891] ptlrpc_main+0x1a2d/0x2da0 [ptlrpc] [ 9051.585214] ? __kthread_parkme+0xc7/0x200 [ 9051.585224] ? ptlrpc_watchdog_init+0x1d0/0x1d0 [ptlrpc] [ 9051.585548] kthread+0x2ab/0x350 [ 9051.585556] ? kthread_insert_work_sanity_check+0xd0/0xd0 [ 9051.585563] ret_from_fork+0x1f/0x30 [ 9051.585577] [ 9051.586050] Lustre: 72237:0:(osd_internal.h:1324:osd_trans_exec_op()) lustre-MDT0001: opcode 0: before 3202 < left 4003, rollback = 0 [ 9064.892730] Lustre: DEBUG MARKER: == sanity test 27Ce: test pool with overstriping ========= 06:24:59 (1743503099) [ 9098.073179] Lustre: DEBUG MARKER: == sanity test 27Cf: test default inheritance with overstriping ========================================================== 06:25:32 (1743503132) [ 9108.432733] Lustre: DEBUG MARKER: == sanity test 27Cg: test setstripe with wrong OST idx === 06:25:43 (1743503143) [ 9117.323666] Lustre: DEBUG MARKER: == sanity test 27Ci: add an overstriping component ======= 06:25:52 (1743503152) [ 9125.707044] Lustre: 72237:0:(osd_handler.c:2067:osd_trans_start()) lustre-MDT0000: credits 3402 > trans_max 3200 [ 9125.707082] Lustre: 72237:0:(osd_handler.c:1961:osd_trans_dump_creds()) create: 4/16/0, destroy: 1/4/0 [ 9125.707105] Lustre: 72237:0:(osd_handler.c:1961:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 9125.707119] Lustre: 72237:0:(osd_handler.c:1968:osd_trans_dump_creds()) attr_set: 205/205/0, xattr_set: 307/2976/0 [ 9125.707124] Lustre: 72237:0:(osd_handler.c:1968:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 9125.707133] Lustre: 72237:0:(osd_handler.c:1975:osd_trans_dump_creds()) write: 20/109/0, punch: 0/0/0, quota 0/0/0 [ 9125.707138] Lustre: 72237:0:(osd_handler.c:1975:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 9125.707146] Lustre: 72237:0:(osd_handler.c:1985:osd_trans_dump_creds()) insert: 5/84/0, delete: 2/5/0 [ 9125.707152] Lustre: 72237:0:(osd_handler.c:1985:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 9125.707161] Lustre: 72237:0:(osd_handler.c:1992:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/0 [ 9125.707165] Lustre: 72237:0:(osd_handler.c:1992:osd_trans_dump_creds()) Skipped 3 previous similar messages [ 9125.707173] CPU: 2 PID: 72237 Comm: mdt00_006 Kdump: loaded Tainted: G W OE ------- --- 5.14.0rocky95-debug #3 [ 9125.707180] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 9125.707184] Call Trace: [ 9125.707188] [ 9125.707195] dump_stack_lvl+0x41/0x5e [ 9125.707254] osd_trans_start+0x120d/0x1920 [osd_ldiskfs] [ 9125.707332] ? mdd_migrate_sanity_check.constprop.0+0x900/0x900 [mdd] [ 9125.707395] top_trans_start+0x661/0xe40 [ptlrpc] [ 9125.707792] mdd_unlink+0x7f0/0x2000 [mdd] [ 9125.707862] mdt_reint_unlink+0x1cee/0x4080 [mdt] [ 9125.707997] mdt_reint_rec+0x268/0x610 [mdt] [ 9125.708114] mdt_reint_internal+0x924/0x1280 [mdt] [ 9125.708224] ? tsi2mdt_info+0x9b/0x370 [mdt] [ 9125.708337] mdt_reint+0xf5/0x2a0 [mdt] [ 9125.708452] tgt_handle_request0+0x281/0x1360 [ptlrpc] [ 9125.708819] tgt_request_handle+0x716/0x1e50 [ptlrpc] [ 9125.709179] ? tgt_blocking_ast+0x10a0/0x10a0 [ptlrpc] [ 9125.709567] ptlrpc_server_handle_request.isra.0+0xa07/0x2220 [ptlrpc] [ 9125.709913] ptlrpc_main+0x1a2d/0x2da0 [ptlrpc] [ 9125.710250] ? __kthread_parkme+0xc7/0x200 [ 9125.710262] ? ptlrpc_watchdog_init+0x1d0/0x1d0 [ptlrpc] [ 9125.710610] kthread+0x2ab/0x350 [ 9125.710618] ? kthread_insert_work_sanity_check+0xd0/0xd0 [ 9125.710626] ret_from_fork+0x1f/0x30 [ 9125.710644] [ 9128.610672] Lustre: DEBUG MARKER: == sanity test 27Cj: overstriping with -C for max values in multiple of targets ========================================================== 06:26:03 (1743503163) [ 9139.207121] Lustre: DEBUG MARKER: == sanity test 27D: validate llapi_layout API ============ 06:26:13 (1743503173) [ 9176.696561] Lustre: DEBUG MARKER: == sanity test 27E: check that default extended attribute size properly increases ========================================================== 06:26:51 (1743503211) [ 9186.020289] Lustre: DEBUG MARKER: == sanity test 27F: Client resend delayed layout creation with non-zero size ========================================================== 06:27:00 (1743503220) [ 9189.253625] Lustre: Failing over lustre-OST0000 [ 9189.387480] LDISKFS-fs (dm-2): unmounting filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f. [ 9189.416151] Lustre: server umount lustre-OST0000 complete [ 9192.170210] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 9192.170435] Lustre: Skipped 1 previous similar message [ 9192.172075] LustreError: 29193:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 9192.172082] LustreError: 29193:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 7 previous similar messages [ 9194.748019] Lustre: Failing over lustre-OST0001 [ 9194.871546] LDISKFS-fs (dm-3): unmounting filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739. [ 9195.059507] Lustre: server umount lustre-OST0001 complete [ 9207.667449] LDISKFS-fs (dm-2): mounted filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f r/w with ordered data mode. Quota mode: journalled. [ 9207.853086] Lustre: 76218:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 9208.068588] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 9208.078606] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 9209.073333] LustreError: 76225:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-OST0001: not available for connect from 192.168.206.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 9209.073369] LustreError: 76225:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 2 previous similar messages [ 9212.139652] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 9213.158356] Lustre: 4135:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743503234/real 1743503234] req@ffff88811d36c640 x1828186622480128/t0(0) o400->lustre-OST0001-osc-MDT0001@0@lo:28/4 lens 224/224 e 0 to 1 dl 1743503250 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 9213.158394] Lustre: 4135:0:(client.c:2340:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 9214.181427] Lustre: 7507:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743503235/real 1743503235] req@ffff88811d36ee40 x1828186622481024/t0(0) o10->lustre-OST0001-osc-MDT0000@0@lo:6/4 lens 440/432 e 0 to 1 dl 1743503251 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'mdt00_002.0' uid:0 gid:0 [ 9214.181469] Lustre: 7507:0:(client.c:2340:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 9214.203109] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 192.168.206.108@tcp (at 0@lo) [ 9214.203141] Lustre: Skipped 1 previous similar message [ 9214.203439] Lustre: lustre-OST0000: Recovery over after 0:02, of 3 clients 3 recovered and 0 were evicted. [ 9215.603688] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 9219.301542] Lustre: 4136:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743503240/real 1743503240] req@ffff8880373a9e40 x1828186622482176/t0(0) o400->lustre-OST0001-osc-MDT0001@0@lo:28/4 lens 224/224 e 0 to 1 dl 1743503256 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 9223.397325] Lustre: 4136:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743503245/real 1743503245] req@ffff88802c322d40 x1828186622483712/t0(0) o400->lustre-OST0001-osc-MDT0000@0@lo:28/4 lens 224/224 e 0 to 1 dl 1743503261 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 9223.397354] Lustre: 4136:0:(client.c:2340:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 9227.495746] LustreError: 76225:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 9227.495771] LustreError: 76225:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 9 previous similar messages [ 9227.563815] LDISKFS-fs (dm-3): mounted filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739 r/w with ordered data mode. Quota mode: journalled. [ 9227.649452] Lustre: 77051:0:(mgc_request_server.c:552:mgc_llog_local_copy()) MGC192.168.206.108@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 9227.835046] Lustre: lustre-OST0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 9227.843826] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [ 9229.002622] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 9229.649089] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 9235.253158] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug all all [ 9247.048687] Lustre: DEBUG MARKER: == sanity test 27G: Clear OST pool from stripe =========== 06:28:01 (1743503281) [ 9278.752218] Lustre: DEBUG MARKER: == sanity test 27H: Set specific OSTs stripe ============= 06:28:33 (1743503313) [ 9281.128520] Lustre: DEBUG MARKER: SKIP: sanity test_27H needs >= 3 OSTs [ 9283.434372] Lustre: DEBUG MARKER: == sanity test 27I: check that root dir striping does not break parent dir one ========================================================== 06:28:38 (1743503318) [ 9315.457991] Lustre: DEBUG MARKER: == sanity test 27Ia: check that root dir pool is dropped with conflict parent dir settings ========================================================== 06:29:10 (1743503350) [ 9347.489356] Lustre: DEBUG MARKER: == sanity test 27J: basic ops on file with foreign LOV === 06:29:42 (1743503382) [ 9358.047812] Lustre: DEBUG MARKER: == sanity test 27K: basic ops on dir with foreign LMV ==== 06:29:52 (1743503392) [ 9368.484990] Lustre: DEBUG MARKER: == sanity test 27L: lfs pool_list gives correct pool name ========================================================== 06:30:03 (1743503403) [ 9392.376067] Lustre: DEBUG MARKER: == sanity test 27M: test O_APPEND striping =============== 06:30:26 (1743503426) [ 9454.184754] Lustre: DEBUG MARKER: == sanity test 27N: lctl pool_list on separate MGS gives correct pool name ========================================================== 06:31:28 (1743503488) [ 9456.372676] Lustre: DEBUG MARKER: SKIP: sanity test_27N needs separate MGS/MDT [ 9458.857566] Lustre: DEBUG MARKER: == sanity test 27O: basic ops on foreign file of symlink type ========================================================== 06:31:33 (1743503493) [ 9471.443768] Lustre: DEBUG MARKER: == sanity test 27P: basic ops on foreign dir of foreign_symlink type ========================================================== 06:31:45 (1743503505) [ 9484.573390] Lustre: DEBUG MARKER: == sanity test 27Q: llapi_file_get_stripe() works on symlinks ========================================================== 06:31:59 (1743503519) [ 9495.651196] Lustre: DEBUG MARKER: == sanity test 27R: test max_stripecount limitation when stripe count is set to -1 ========================================================== 06:32:10 (1743503530) [ 9510.705712] Lustre: DEBUG MARKER: == sanity test 27T: no eio on close on partial write due to enosp ========================================================== 06:32:25 (1743503545) [ 9514.491394] Lustre: *** cfs_fail_loc=255, val=0*** [ 9524.181660] Lustre: DEBUG MARKER: == sanity test 27U: append pool and stripe count work with composite default layout ========================================================== 06:32:38 (1743503558) [ 9596.353687] Lustre: DEBUG MARKER: == sanity test 27V: creating widely striped file races with deactivating OST ========================================================== 06:33:50 (1743503630) [ 9598.802182] Lustre: DEBUG MARKER: SKIP: sanity test_27V needs >= 4 OSTs [ 9601.381158] Lustre: DEBUG MARKER: == sanity test 27W: test enable_setstripe_gid ============ 06:33:55 (1743503635) [ 9611.913127] Lustre: DEBUG MARKER: == sanity test 28: create/mknod/mkdir with bad file types ====================================================================== 06:34:06 (1743503646) [ 9623.036327] Lustre: DEBUG MARKER: == sanity test 29: IT_GETATTR regression ====================================================================================== 06:34:17 (1743503657) [ 9626.833327] Lustre: DEBUG MARKER: first d29 [ 9629.239831] Lustre: DEBUG MARKER: second d29 [ 9631.416845] Lustre: DEBUG MARKER: done [ 9640.820803] Lustre: DEBUG MARKER: == sanity test 30a: execute binary from Lustre (execve) ======================================================================== 06:34:35 (1743503675) [ 9650.032352] Lustre: DEBUG MARKER: == sanity test 30b: execute binary from Lustre as non-root ===================================================================== 06:34:44 (1743503684) [ 9659.428734] Lustre: DEBUG MARKER: == sanity test 30c: execute binary from Lustre without read perms ============================================================== 06:34:54 (1743503694) [ 9668.866932] Lustre: DEBUG MARKER: == sanity test 30d: execute binary from Lustre while clear locks ========================================================== 06:35:03 (1743503703) [ 9839.065550] Lustre: DEBUG MARKER: == sanity test 31a: open-unlink file ============================================================================================ 06:37:53 (1743503873) [ 9848.121058] Lustre: DEBUG MARKER: == sanity test 31b: unlink file with multiple links while open ================================================================= 06:38:02 (1743503882) [ 9857.315296] Lustre: DEBUG MARKER: == sanity test 31c: open-unlink file with multiple links ======================================================================= 06:38:11 (1743503891) [ 9866.477895] Lustre: DEBUG MARKER: == sanity test 31d: remove of open directory =================================================================================== 06:38:21 (1743503901) [ 9875.706502] Lustre: DEBUG MARKER: == sanity test 31e: remove of open non-empty directory ========================================================================= 06:38:30 (1743503910) [ 9884.682272] Lustre: DEBUG MARKER: == sanity test 31f: remove of open directory with open-unlink file ============================================================= 06:38:39 (1743503919) [ 9900.544512] Lustre: DEBUG MARKER: == sanity test 31g: cross directory link================== 06:38:55 (1743503935) [ 9909.419091] Lustre: DEBUG MARKER: == sanity test 31h: cross directory link under child========================================================================= 06:39:04 (1743503944) [ 9918.599872] Lustre: DEBUG MARKER: == sanity test 31i: cross directory link under parent========================================================================= 06:39:13 (1743503953) [ 9927.990901] Lustre: DEBUG MARKER: == sanity test 31j: link for directory =================== 06:39:22 (1743503962) [ 9937.212420] Lustre: DEBUG MARKER: == sanity test 31k: link to file: the same, non-existing, dir ========================================================== 06:39:31 (1743503971) [ 9946.293489] Lustre: DEBUG MARKER: == sanity test 31l: link to file: target dir has trailing slash ========================================================== 06:39:41 (1743503981) [ 9955.522596] Lustre: DEBUG MARKER: == sanity test 31m: link to file: the same, non-existing, dir ========================================================== 06:39:50 (1743503990) [ 9964.943729] Lustre: DEBUG MARKER: == sanity test 31n: check link count of unlinked file ==== 06:39:59 (1743503999) [ 9973.454621] Lustre: DEBUG MARKER: == sanity test 31o: duplicate hard links with same filename ========================================================== 06:40:08 (1743504008) [10044.501783] Lustre: DEBUG MARKER: == sanity test 31p: remove of open striped directory ===== 06:41:19 (1743504079) [10054.016183] Lustre: DEBUG MARKER: == sanity test 31q: create striped directory on specific MDTs ========================================================== 06:41:28 (1743504088) [10056.296671] Lustre: DEBUG MARKER: SKIP: sanity test_31q needs >= 3 MDTs [10058.974809] Lustre: DEBUG MARKER: == sanity test 31r: open-rename(replace) race ============ 06:41:33 (1743504093) [10070.208619] Lustre: DEBUG MARKER: == sanity test 32a: stat d32a/ext2-mountpoint/.. =============================================================================== 06:41:44 (1743504104) [10080.906384] Lustre: DEBUG MARKER: == sanity test 32b: open d32b/ext2-mountpoint/.. =============================================================================== 06:41:55 (1743504115) [10090.472090] Lustre: DEBUG MARKER: == sanity test 32c: stat d32c/ext2-mountpoint/../d2/test_dir =================================================================== 06:42:05 (1743504125) [10100.565695] Lustre: DEBUG MARKER: == sanity test 32d: open d32d/ext2-mountpoint/../d2/test_dir ========================================================== 06:42:15 (1743504135) [10110.681804] Lustre: DEBUG MARKER: == sanity test 32e: stat d32e/symlink->tmp/symlink->lustre-subdir ========================================================== 06:42:25 (1743504145) [10119.751922] Lustre: DEBUG MARKER: == sanity test 32f: open d32f/symlink->tmp/symlink->lustre-subdir ========================================================== 06:42:34 (1743504154) [10129.584055] Lustre: DEBUG MARKER: == sanity test 32g: stat d32g/symlink->tmp/symlink->lustre-subdir/2 ========================================================== 06:42:43 (1743504163) [10140.562473] Lustre: DEBUG MARKER: == sanity test 32h: open d32h/symlink->tmp/symlink->lustre-subdir/2 ========================================================== 06:42:54 (1743504174) [10150.032974] Lustre: DEBUG MARKER: == sanity test 32i: stat d32i/ext2-mountpoint/../test_file ===================================================================== 06:43:04 (1743504184) [10159.746220] Lustre: DEBUG MARKER: == sanity test 32j: open d32j/ext2-mountpoint/../test_file ===================================================================== 06:43:14 (1743504194) [10168.948146] Lustre: DEBUG MARKER: == sanity test 32k: stat d32k/ext2-mountpoint/../d2/test_file ================================================================== 06:43:23 (1743504203) [10180.386581] Lustre: DEBUG MARKER: == sanity test 32l: open d32l/ext2-mountpoint/../d2/test_file ================================================================== 06:43:34 (1743504214) [10191.437057] Lustre: DEBUG MARKER: == sanity test 32m: stat d32m/symlink->tmp/symlink->lustre-root ================================================================ 06:43:45 (1743504225) [10200.642544] Lustre: DEBUG MARKER: == sanity test 32n: open d32n/symlink->tmp/symlink->lustre-root ================================================================ 06:43:55 (1743504235) [10210.102278] Lustre: DEBUG MARKER: == sanity test 32o: stat d32o/symlink->tmp/symlink->lustre-root/ ========================================================== 06:44:04 (1743504244) [10219.099513] Lustre: DEBUG MARKER: == sanity test 32p: open d32p/symlink->tmp/symlink->lustre-root/ ========================================================== 06:44:13 (1743504253) [10221.761932] Lustre: DEBUG MARKER: 32p_1 [10224.188182] Lustre: DEBUG MARKER: 32p_2 [10226.718334] Lustre: DEBUG MARKER: 32p_3 [10229.273754] Lustre: DEBUG MARKER: 32p_4 [10231.996933] Lustre: DEBUG MARKER: 32p_5 [10234.422515] Lustre: DEBUG MARKER: 32p_6 [10236.701990] Lustre: DEBUG MARKER: 32p_7 [10239.004286] Lustre: DEBUG MARKER: 32p_8 [10241.624159] Lustre: DEBUG MARKER: 32p_9 [10244.289332] Lustre: DEBUG MARKER: 32p_10 [10254.659209] Lustre: DEBUG MARKER: == sanity test 32q: stat follows mountpoints in Lustre (should return error) ========================================================== 06:44:48 (1743504288) [10266.103418] Lustre: DEBUG MARKER: == sanity test 32r: opendir follows mountpoints in Lustre (should return error) ========================================================== 06:45:00 (1743504300) [10277.291164] Lustre: DEBUG MARKER: == sanity test 33aa: write file with mode 444 (should return error) ========================================================== 06:45:11 (1743504311) [10279.712465] Lustre: DEBUG MARKER: 33_1 [10282.114287] Lustre: DEBUG MARKER: 33_2 [10292.245394] Lustre: DEBUG MARKER: == sanity test 33a: test open file(mode=0444) with O_RDWR (should return error) ========================================================== 06:45:26 (1743504326) [10302.853137] Lustre: DEBUG MARKER: == sanity test 33b: test open file with malformed flags (No panic) ========================================================== 06:45:37 (1743504337) [10312.244392] Lustre: DEBUG MARKER: == sanity test 33c: test write_bytes stats =============== 06:45:46 (1743504346) [10322.954039] Lustre: DEBUG MARKER: == sanity test 33d: openfile with 444 modes and malformed flags under remote dir ========================================================== 06:45:57 (1743504357) [10332.291375] Lustre: DEBUG MARKER: == sanity test 33e: mkdir and striped directory should have same mode ========================================================== 06:46:07 (1743504367) [10342.433262] Lustre: DEBUG MARKER: == sanity test 33f: nonroot user can create, access, and remove a striped directory ========================================================== 06:46:17 (1743504377) [10354.840897] Lustre: DEBUG MARKER: == sanity test 33g: nonroot user create already existing root created file ========================================================== 06:46:29 (1743504389) [10363.780842] Lustre: DEBUG MARKER: == sanity test 33h: temp file is located on the same MDT as target (crush) ========================================================== 06:46:38 (1743504398) [10457.387184] Lustre: DEBUG MARKER: == sanity test 33hh: temp file is located on the same MDT as target (crush2) ========================================================== 06:48:12 (1743504492) [10551.525351] Lustre: DEBUG MARKER: == sanity test 33i: striped directory can be accessed when one MDT is down ========================================================== 06:49:46 (1743504586) [10552.935251] workqueue: drain_vmap_area_work hogged CPU for >10000us 19 times, consider switching to WQ_UNBOUND [10583.779062] Lustre: lustre-MDT0001: Client c0269f7d-ea0d-48f7-af7f-b6c8f1877996 (at 192.168.206.8@tcp) reconnecting [10585.969598] Lustre: DEBUG MARKER: == sanity test 33j: lfs setdirstripe -D -i x,y,x should fail ========================================================== 06:50:20 (1743504620) [10595.377278] Lustre: DEBUG MARKER: == sanity test 34a: truncate file that has not been opened ===================================================================== 06:50:29 (1743504629) [10605.582051] Lustre: DEBUG MARKER: == sanity test 34b: O_RDONLY opening file doesn't create objects =============================================================== 06:50:40 (1743504640) [10615.652343] Lustre: DEBUG MARKER: == sanity test 34c: O_RDWR opening file-with-size works ======================================================================== 06:50:50 (1743504650) [10624.814751] Lustre: DEBUG MARKER: == sanity test 34d: write to sparse file ======================================================================================= 06:50:59 (1743504659) [10634.017856] Lustre: DEBUG MARKER: == sanity test 34e: create objects, some with size and some without ============================================================ 06:51:08 (1743504668) [10642.797901] Lustre: DEBUG MARKER: == sanity test 34f: read from a file with no objects until EOF ================================================================= 06:51:17 (1743504677) [10651.328508] Lustre: DEBUG MARKER: == sanity test 34g: truncate long file ========================================================================================= 06:51:26 (1743504686) [10660.432276] Lustre: DEBUG MARKER: == sanity test 34h: ftruncate file under grouplock should not block ========================================================== 06:51:35 (1743504695) [10672.143229] Lustre: DEBUG MARKER: == sanity test 35a: exec file with mode 444 (should return and not leak) ========================================================== 06:51:47 (1743504707) [10681.554418] Lustre: DEBUG MARKER: == sanity test 36a: MDS utime check (mknod, utime) ======= 06:51:56 (1743504716) [10690.086224] Lustre: DEBUG MARKER: == sanity test 36b: OST utime check (open, utime) ======== 06:52:04 (1743504724) [10699.287145] Lustre: DEBUG MARKER: == sanity test 36c: non-root MDS utime check (mknod, utime) ========================================================== 06:52:13 (1743504733) [10708.941744] Lustre: DEBUG MARKER: == sanity test 36d: non-root OST utime check (open, utime) ========================================================== 06:52:23 (1743504743) [10717.909058] Lustre: DEBUG MARKER: == sanity test 36e: utime on non-owned file (should return error) ========================================================== 06:52:32 (1743504752) [10726.895619] Lustre: DEBUG MARKER: == sanity test 36f: utime on file racing with OST BRW write ==================================================================== 06:52:41 (1743504761) [10737.201178] Lustre: DEBUG MARKER: == sanity test 36g: FMD cache expiry =============================================================================== 06:52:51 (1743504771) [10793.660419] Lustre: DEBUG MARKER: == sanity test 36h: utime on file racing with OST BRW write ==================================================================== 06:53:48 (1743504828) [10803.596579] Lustre: DEBUG MARKER: == sanity test 36i: change mtime on striped directory ==== 06:53:58 (1743504838) [10812.756561] Lustre: DEBUG MARKER: == sanity test 38: open a regular file with O_DIRECTORY should return -ENOTDIR ============================================================= 06:54:07 (1743504847) [10822.058890] Lustre: DEBUG MARKER: == sanity test 39a: mtime changed on create ============== 06:54:16 (1743504856) [10833.375658] Lustre: DEBUG MARKER: == sanity test 39b: mtime change on open, link, unlink, rename ================================================================ 06:54:28 (1743504868) [10844.286698] Lustre: DEBUG MARKER: == sanity test 39c: mtime change on rename ===================================================================================== 06:54:39 (1743504879) [10855.713994] Lustre: DEBUG MARKER: == sanity test 39d: create, utime, stat ======================================================================================== 06:54:50 (1743504890) [10864.662605] Lustre: DEBUG MARKER: == sanity test 39e: create, stat, utime, stat ================================================================================== 06:54:59 (1743504899) [10873.748804] Lustre: DEBUG MARKER: == sanity test 39f: create, stat, sleep, utime, stat =========================================================================== 06:55:08 (1743504908) [10884.863971] Lustre: DEBUG MARKER: == sanity test 39g: write, chmod, stat ========================================================================================= 06:55:19 (1743504919) [10895.979207] Lustre: DEBUG MARKER: == sanity test 39h: write, utime within one second, stat ======================================================================= 06:55:30 (1743504930) [10906.574927] Lustre: DEBUG MARKER: == sanity test 39i: write, rename, stat ======================================================================================== 06:55:41 (1743504941) [10917.136080] Lustre: DEBUG MARKER: == sanity test 39j: write, rename, close, stat ================================================================================= 06:55:51 (1743504951) [10947.086732] Lustre: DEBUG MARKER: == sanity test 39k: write, utime, close, stat ================================================================================== 06:56:21 (1743504981) [10957.752455] Lustre: DEBUG MARKER: == sanity test 39l: directory atime update ===================================================================================== 06:56:32 (1743504992) [10978.564045] Lustre: DEBUG MARKER: == sanity test 39m: test atime and mtime before 1970 ===== 06:56:53 (1743505013) [10989.719972] Lustre: DEBUG MARKER: == sanity test 39n: check that O_NOATIME is honored ====== 06:57:04 (1743505024) [11012.768585] Lustre: DEBUG MARKER: == sanity test 39o: directory cached attributes updated after create ========================================================== 06:57:27 (1743505047) [11021.836579] Lustre: DEBUG MARKER: == sanity test 39p: remote directory cached attributes updated after create ================================================================== 06:57:36 (1743505056) [11031.207892] Lustre: DEBUG MARKER: == sanity test 39r: lazy atime update on OST ============= 06:57:45 (1743505065) [11059.884881] Lustre: DEBUG MARKER: == sanity test 39q: close won't zero out atime =========== 06:58:14 (1743505094) [11069.446810] Lustre: DEBUG MARKER: == sanity test 39s: relatime is supported ================ 06:58:24 (1743505104) [11089.279198] Lustre: DEBUG MARKER: == sanity test 39u: stat race ============================ 06:58:43 (1743505123) [11113.048015] Lustre: DEBUG MARKER: == sanity test 40: failed open(O_TRUNC) doesn't truncate ======================================================================= 06:59:07 (1743505147) [11121.754590] Lustre: DEBUG MARKER: == sanity test 41: test small file write + fstat =============================================================================== 06:59:16 (1743505156) [11131.095967] Lustre: DEBUG MARKER: SKIP: sanity test_42a skipping ALWAYS excluded test 42a [11133.165513] Lustre: DEBUG MARKER: SKIP: sanity test_42b skipping ALWAYS excluded test 42b [11135.114195] Lustre: DEBUG MARKER: SKIP: sanity test_42c skipping ALWAYS excluded test 42c [11137.386778] Lustre: DEBUG MARKER: == sanity test 42d: test complete truncate of file with cached dirty data ========================================================== 06:59:32 (1743505172) [11149.644030] Lustre: DEBUG MARKER: == sanity test 42e: verify sub-RPC writes are not done synchronously ========================================================== 06:59:44 (1743505184) [11376.730848] Lustre: DEBUG MARKER: == sanity test 43A: execution of file opened for write should return -ETXTBSY ========================================================== 07:03:31 (1743505411) [11387.024576] Lustre: DEBUG MARKER: == sanity test 43a: open(RDWR) of file being executed should return -ETXTBSY ========================================================== 07:03:41 (1743505421) [11397.212815] Lustre: DEBUG MARKER: == sanity test 43b: truncate of file being executed should return -ETXTBSY ========================================================== 07:03:52 (1743505432) [11407.800302] Lustre: DEBUG MARKER: == sanity test 43c: md5sum of copy into lustre =========== 07:04:02 (1743505442) [11417.665461] Lustre: DEBUG MARKER: == sanity test 44A: zero length read from a sparse stripe ========================================================== 07:04:12 (1743505452) [11426.972868] Lustre: DEBUG MARKER: == sanity test 44a: test sparse pwrite ========================================================================================= 07:04:21 (1743505461) [11439.088956] Lustre: DEBUG MARKER: == sanity test 44b: write one byte at offset 0xfffffffe000 ========================================================== 07:04:34 (1743505474) [11447.707143] Lustre: DEBUG MARKER: == sanity test 44c: write 1 byte at max_object_bytes - 1 offset ========================================================== 07:04:42 (1743505482) [11456.356273] Lustre: DEBUG MARKER: == sanity test 44d: if write at position fails (EFBIG), so should do append ========================================================== 07:04:51 (1743505491) [11464.826473] Lustre: DEBUG MARKER: == sanity test 44e: write and read maximal stripes ======= 07:04:59 (1743505499) [11491.679539] Lustre: DEBUG MARKER: == sanity test 44f: Check fiemap for sparse files ======== 07:05:26 (1743505526) [13006.060862] Lustre: DEBUG MARKER: == sanity test 45: osc io page accounting ================ 07:30:40 (1743507040) [13023.807156] Lustre: DEBUG MARKER: == sanity test 46: dirtying a previously written page ========================================================================== 07:30:58 (1743507058) [13033.796133] Lustre: DEBUG MARKER: == sanity test 48a: Access renamed working dir (should return errors)=========================================================== 07:31:08 (1743507068) [13044.882076] Lustre: DEBUG MARKER: == sanity test 48b: Access removed working dir (should return errors)=========================================================== 07:31:19 (1743507079) [13055.033185] Lustre: DEBUG MARKER: == sanity test 48c: Access removed working subdir (should return errors) ========================================================== 07:31:29 (1743507089) [13064.377535] Lustre: DEBUG MARKER: == sanity test 48d: Access removed parent subdir (should return errors) ========================================================== 07:31:39 (1743507099) [13073.981380] Lustre: DEBUG MARKER: == sanity test 48e: Access to recreated parent subdir (should return errors) ========================================================== 07:31:48 (1743507108) [13083.484519] Lustre: DEBUG MARKER: == sanity test 48f: non-zero nlink dir unlink won't LBUG() ========================================================== 07:31:58 (1743507118) [13086.003772] Lustre: DEBUG MARKER: SKIP: sanity test_48f needs different host for mdt1 mdt2 [13088.554375] Lustre: DEBUG MARKER: == sanity test 49: Change max_pages_per_rpc won't break osc extent ========================================================== 07:32:03 (1743507123) [13100.294114] Lustre: DEBUG MARKER: == sanity test 50: special situations: /proc symlinks ========================================================================= 07:32:14 (1743507134) [13109.774497] Lustre: DEBUG MARKER: == sanity test 51a: special situations: split htree with empty entry ============================================================ 07:32:24 (1743507144) [13126.117026] Lustre: DEBUG MARKER: == sanity test 51b: exceed 64k subdirectory nlink limit on create, verify unlink ========================================================== 07:32:40 (1743507160) [13314.542251] workqueue: rht_deferred_worker hogged CPU for >10000us 19 times, consider switching to WQ_UNBOUND [13885.432172] Lustre: DEBUG MARKER: == sanity test 51d: check LOV round-robin OST object distribution ========================================================== 07:45:20 (1743507920) [13887.579742] Lustre: DEBUG MARKER: SKIP: sanity test_51d needs >= 3 OSTs [13890.081157] Lustre: DEBUG MARKER: == sanity test 51e: check file nlink limit =============== 07:45:24 (1743507924) [14105.840250] workqueue: nfs4_renew_state hogged CPU for >10000us 4 times, consider switching to WQ_UNBOUND [14708.979220] Lustre: DEBUG MARKER: == sanity test 51f: check many open files limit ========== 07:59:03 (1743508743) [15028.957726] Lustre: DEBUG MARKER: == sanity test 52a: append-only flag test (should return errors) ========================================================== 08:04:23 (1743509063) [15038.946330] Lustre: DEBUG MARKER: == sanity test 52b: immutable flag test (should return errors) ================================================================= 08:04:33 (1743509073) [15047.848203] Lustre: DEBUG MARKER: == sanity test 53: verify that MDS and OSTs agree on pre-creation ============================================================== 08:04:42 (1743509082) [15065.808065] Lustre: DEBUG MARKER: == sanity test 54a: unix domain socket test ============== 08:05:00 (1743509100) [15074.452080] Lustre: DEBUG MARKER: == sanity test 54b: char device works in lustre ================================================================================ 08:05:09 (1743509109) [15082.805920] Lustre: DEBUG MARKER: == sanity test 54c: block device works in lustre =============================================================================== 08:05:17 (1743509117) [15092.551901] Lustre: DEBUG MARKER: == sanity test 54d: fifo device works in lustre ================================================================================ 08:05:27 (1743509127) [15100.980440] Lustre: DEBUG MARKER: == sanity test 54e: console/tty device works in lustre ================================================================================ 08:05:35 (1743509135) [15109.510595] Lustre: DEBUG MARKER: == sanity test 55a: OBD device life cycle unit tests ===== 08:05:44 (1743509144) [15119.054672] Lustre: DEBUG MARKER: == sanity test 55b: Load and unload max OBD devices ====== 08:05:53 (1743509153) [15683.188046] Lustre: DEBUG MARKER: == sanity test 56a: check /home/green/git/lustre-release/lustre/utils/lfs getstripe ========================================================== 08:15:18 (1743509718) [15694.022588] Lustre: DEBUG MARKER: == sanity test 56b: check /home/green/git/lustre-release/lustre/utils/lfs getdirstripe ========================================================== 08:15:28 (1743509728) [15702.792930] Lustre: DEBUG MARKER: == sanity test 56bb: check /home/green/git/lustre-release/lustre/utils/lfs getdirstripe layout is YAML ========================================================== 08:15:37 (1743509737) [15711.711974] Lustre: DEBUG MARKER: == sanity test 56bc: check '/home/green/git/lustre-release/lustre/utils/lfs getdirstripe --yaml' params are valid ========================================================== 08:15:46 (1743509746) [15722.308424] Lustre: DEBUG MARKER: == sanity test 56c: check 'lfs df' showing device status ========================================================== 08:15:56 (1743509756) [15760.735852] Lustre: DEBUG MARKER: == sanity test 56d: 'lfs df -v' prints only configured devices ========================================================== 08:16:35 (1743509795) [15769.989265] Lustre: DEBUG MARKER: == sanity test 56e: 'lfs df' Handle non LustreFS [15779.244599] Lustre: DEBUG MARKER: == sanity test 56g: check lfs find -name ================= 08:16:53 (1743509813) [15791.064386] Lustre: DEBUG MARKER: == sanity test 56h: check lfs find ! -name =============== 08:17:05 (1743509825) [15799.645556] Lustre: DEBUG MARKER: == sanity test 56i: check 'lfs find -ost UUID' skips directories ========================================================== 08:17:14 (1743509834) [15808.776576] Lustre: DEBUG MARKER: == sanity test 56ib: check 'lfs find -ost INDEX_RANGE' command ========================================================== 08:17:23 (1743509843) [15817.840362] Lustre: DEBUG MARKER: == sanity test 56j: check lfs find -type d =============== 08:17:32 (1743509852) [15826.917707] Lustre: DEBUG MARKER: == sanity test 56k: check lfs find -type f =============== 08:17:41 (1743509861) [15835.820336] Lustre: DEBUG MARKER: == sanity test 56l: check lfs find -type b =============== 08:17:50 (1743509870) [15846.507429] Lustre: DEBUG MARKER: == sanity test 56m: check lfs find -type c =============== 08:18:00 (1743509880) [15855.044053] Lustre: DEBUG MARKER: == sanity test 56n: check lfs find -type l =============== 08:18:09 (1743509889) [15864.340705] Lustre: DEBUG MARKER: == sanity test 56o: check lfs find -mtime for old files == 08:18:18 (1743509898) [15875.685887] Lustre: DEBUG MARKER: == sanity test 56ob: check lfs find -atime -mtime -ctime with units ========================================================== 08:18:30 (1743509910) [15888.844084] Lustre: DEBUG MARKER: SKIP: sanity test_56oc skipping excluded test 56oc [15890.953697] Lustre: DEBUG MARKER: == sanity test 56od: check lfs find -btime with units ==== 08:18:45 (1743509925) [15910.072526] Lustre: DEBUG MARKER: == sanity test 56oe: check lfs find with time range ====== 08:19:04 (1743509944) [15944.675437] Lustre: DEBUG MARKER: == sanity test 56p: check lfs find -uid and ! -uid ======= 08:19:39 (1743509979) [15956.064111] Lustre: DEBUG MARKER: == sanity test 56q: check lfs find -gid and ! -gid ======= 08:19:50 (1743509990) [15968.400098] Lustre: DEBUG MARKER: == sanity test 56r: check lfs find -size works =========== 08:20:02 (1743510002) [15982.192150] Lustre: DEBUG MARKER: == sanity test 56ra: check lfs find -size -lazy works for data on OSTs ========================================================== 08:20:17 (1743510017) [15996.683386] Lustre: DEBUG MARKER: == sanity test 56rb: check lfs find --size --ost/--mdt works ========================================================== 08:20:31 (1743510031) [16006.660748] Lustre: DEBUG MARKER: == sanity test 56rc: check lfs find --mdt-count/--mdt-hash works ========================================================== 08:20:41 (1743510041) [16020.568557] Lustre: DEBUG MARKER: == sanity test 56rd: check lfs find --printf special files ========================================================== 08:20:55 (1743510055) [16029.358262] Lustre: DEBUG MARKER: == sanity test 56re: check lfs find -printf width format specifiers are consistant with regular find ========================================================== 08:21:04 (1743510064) [16040.332538] Lustre: DEBUG MARKER: == sanity test 56rf: check lfs find -printf width format specifiers for lustre specific formats ========================================================== 08:21:14 (1743510074) [16063.209719] Lustre: DEBUG MARKER: == sanity test 56s: check lfs find -stripe-count works === 08:21:37 (1743510097) [16073.603597] Lustre: DEBUG MARKER: == sanity test 56t: check lfs find -stripe-size works ==== 08:21:48 (1743510108) [16085.660218] Lustre: DEBUG MARKER: == sanity test 56u: check lfs find -stripe-index works === 08:22:00 (1743510120) [16096.311446] Lustre: DEBUG MARKER: == sanity test 56v: check 'lfs find -m match with lfs getstripe -m' ========================================================== 08:22:11 (1743510131) [16106.813532] Lustre: DEBUG MARKER: == sanity test 56wa: check lfs_migrate -c stripe_count works ========================================================== 08:22:21 (1743510141) [16173.829776] Lustre: DEBUG MARKER: == sanity test 56wb: check lfs_migrate pool support ====== 08:23:28 (1743510208) [16204.849767] Lustre: DEBUG MARKER: == sanity test 56wc: check unrecognized options for lfs_migrate are passed through ========================================================== 08:23:59 (1743510239) [16233.675365] Lustre: DEBUG MARKER: == sanity test 56wd: check lfs_migrate --rsync and --no-rsync work ========================================================== 08:24:28 (1743510268) [16242.845490] Lustre: DEBUG MARKER: == sanity test 56we: check lfs_migrate --non-direct|-D support ========================================================== 08:24:37 (1743510277) [16252.274519] Lustre: DEBUG MARKER: == sanity test 56x: lfs migration support ================ 08:24:47 (1743510287) [16261.634265] Lustre: DEBUG MARKER: == sanity test 56xa: lfs migration --block support ======= 08:24:56 (1743510296) [16270.739276] Lustre: DEBUG MARKER: == sanity test 56xb: lfs migration hard link support ===== 08:25:05 (1743510305) [16509.860639] Lustre: DEBUG MARKER: == sanity test 56xc: lfs migration autostripe ============ 08:29:04 (1743510544) [16521.181362] Lustre: DEBUG MARKER: == sanity test 56xd: check lfs_migrate --yaml and --copy support ========================================================== 08:29:15 (1743510555) [16537.813861] Lustre: DEBUG MARKER: == sanity test 56xe: migrate a composite layout file ===== 08:29:32 (1743510572) [16560.000585] Lustre: DEBUG MARKER: == sanity test 56xf: FID is not lost during migration of a composite layout file ========================================================== 08:29:54 (1743510594) [16572.787036] Lustre: DEBUG MARKER: == sanity test 56xg: lfs migrate pool support ============ 08:30:07 (1743510607) [16652.886146] Lustre: DEBUG MARKER: == sanity test 56xh: lfs migrate bandwidth limitation support ========================================================== 08:31:27 (1743510687) [16692.550085] Lustre: DEBUG MARKER: == sanity test 56xi: lfs migrate stats support =========== 08:32:07 (1743510727) [16704.964971] Lustre: DEBUG MARKER: == sanity test 56xj: lfs migrate -b should not cause starvation of threads on OSS ========================================================== 08:32:19 (1743510739) [16754.303568] Lustre: DEBUG MARKER: == sanity test 56xk: lfs mirror resync bandwidth limitation support ========================================================== 08:33:09 (1743510789) [16770.987861] Lustre: DEBUG MARKER: == sanity test 56xl: lfs mirror resync stats support ===== 08:33:25 (1743510805) [16786.193637] Lustre: DEBUG MARKER: == sanity test 56y: lfs find -L raid0|released =========== 08:33:40 (1743510820) [16797.456212] Lustre: DEBUG MARKER: == sanity test 56z: lfs find should continue after an error ========================================================== 08:33:51 (1743510831) [16812.447415] Lustre: DEBUG MARKER: == sanity test 56aa: lfs find --size under striped dir === 08:34:07 (1743510847) [16844.117430] Lustre: DEBUG MARKER: == sanity test 56ab: lfs find --blocks =================== 08:34:38 (1743510878) [16857.778822] Lustre: DEBUG MARKER: == sanity test 56aca: check lfs find -perm with octal representation ========================================================== 08:34:52 (1743510892) [16887.011108] Lustre: DEBUG MARKER: == sanity test 56acb: check lfs find -perm with symbolic representation ========================================================== 08:35:21 (1743510921) [16903.316765] Lustre: DEBUG MARKER: == sanity test 56acc: check parsing error for lfs find -perm ========================================================== 08:35:37 (1743510937) [16914.017957] Lustre: DEBUG MARKER: == sanity test 56ba: test lfs find --component-end, -start, -count, and -flags ========================================================== 08:35:48 (1743510948) [16931.470412] Lustre: DEBUG MARKER: == sanity test 56ca: check lfs find --mirror-count|-N and --mirror-state ========================================================== 08:36:05 (1743510965) [16943.955226] Lustre: DEBUG MARKER: == sanity test 56da: test lfs find with long paths ======= 08:36:18 (1743510978) [16961.975174] Lustre: DEBUG MARKER: == sanity test 56db: test 'lfs df -m' only shows MDT devices ========================================================== 08:36:36 (1743510996) [16971.729062] Lustre: DEBUG MARKER: == sanity test 56dc: test 'lfs df -o' only shows OST devices ========================================================== 08:36:46 (1743511006) [16981.688551] Lustre: DEBUG MARKER: == sanity test 56dd: test lfs find with mindepth argument ========================================================== 08:36:56 (1743511016) [16991.015620] Lustre: DEBUG MARKER: == sanity test 56ea: test lfs find -printf option ======== 08:37:05 (1743511025) [17026.759951] Lustre: DEBUG MARKER: == sanity test 56eaa: test lfs find -printf added functions ========================================================== 08:37:41 (1743511061) [17224.786813] Lustre: DEBUG MARKER: == sanity test 56eab: test lfs find -ls function ========= 08:40:59 (1743511259) [17241.847999] Lustre: DEBUG MARKER: == sanity test 56eb: check lfs getstripe on symlink ====== 08:41:16 (1743511276) [17251.258524] Lustre: DEBUG MARKER: == sanity test 56ebb: check /home/green/git/lustre-release/lustre/utils/lfs getdirstripe for FIFO file ========================================================== 08:41:26 (1743511286) [17260.763771] Lustre: DEBUG MARKER: == sanity test 56ec: check lfs getstripe,setstripe --hex --yaml ========================================================== 08:41:35 (1743511295) [17270.385057] Lustre: DEBUG MARKER: == sanity test 56ed: verify new YAML format is valid and back-compatible ========================================================== 08:41:45 (1743511305) [17295.347548] Lustre: DEBUG MARKER: == sanity test 56eda: check lfs find --links ============= 08:42:10 (1743511330) [17305.576078] Lustre: DEBUG MARKER: == sanity test 56edb: check lfs find --links for directory striped on multiple MDTs ========================================================== 08:42:20 (1743511340) [17315.481559] Lustre: DEBUG MARKER: == sanity test 56ef: lfs find with multiple paths ======== 08:42:29 (1743511349) [17326.823843] Lustre: DEBUG MARKER: == sanity test 56eg: lfs find -xattr ===================== 08:42:41 (1743511361) [17338.370165] Lustre: DEBUG MARKER: == sanity test 56eh: check lfs find --skip =============== 08:42:52 (1743511372) [17352.933855] Lustre: DEBUG MARKER: == sanity test 56ei: test lfs find --printf prints correct projid for special files ========================================================== 08:43:07 (1743511387) [17362.575794] Lustre: DEBUG MARKER: == sanity test 56ej: lfs migration --non-block copy ====== 08:43:17 (1743511397) [17372.562340] Lustre: DEBUG MARKER: == sanity test 57a: verify MDS filesystem created with large inodes ============================================================ 08:43:26 (1743511406) [17386.757309] Lustre: DEBUG MARKER: == sanity test 57b: default LOV EAs are stored inside large inodes ============================================================= 08:43:41 (1743511421) [17406.442727] Lustre: DEBUG MARKER: == sanity test 58: verify cross-platform wire constants ======================================================================== 08:44:01 (1743511441) [17416.907977] Lustre: DEBUG MARKER: == sanity test 59: verify cancellation of llog records async =================================================================== 08:44:11 (1743511451) [17469.187972] Lustre: DEBUG MARKER: == sanity test complete, duration 15949 sec ============== 08:45:03 (1743511503) [17472.062699] Lustre: DEBUG MARKER: === sanity: start cleanup 08:45:06 (1743511506) === [17571.081942] Lustre: DEBUG MARKER: === sanity: finish cleanup 08:46:45 (1743511605) === [17573.856005] Lustre: Failing over lustre-MDT0000 [17574.185430] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [17575.152249] workqueue: nfs4_renew_state hogged CPU for >10000us 5 times, consider switching to WQ_UNBOUND [17575.168287] LustreError: lustre-MDT0000-osp-MDT0001: operation out_update to node 0@lo failed: rc = -107 [17575.168325] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [17575.168330] Lustre: Skipped 3 previous similar messages [17575.169146] LustreError: 76234:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [17575.169154] LustreError: 76234:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 1 previous similar message [17576.024431] Lustre: server umount lustre-MDT0000 complete [17581.287769] LustreError: 76234:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [17581.287804] LustreError: 76234:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 5 previous similar messages [17591.525484] Lustre: 4135:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743511613/real 1743511613] req@ffff88802df12d40 x1828186636654464/t0(0) o400->MGC192.168.206.108@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1743511629 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [17591.525537] Lustre: 4135:0:(client.c:2340:ptlrpc_expire_one_request()) Skipped 1 previous similar message [17591.525757] LustreError: MGC192.168.206.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [17591.527579] LustreError: 130011:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [17591.527599] LustreError: 130011:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 9 previous similar messages [17608.940562] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.8@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [17608.940595] LustreError: 19396:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 20 previous similar messages [17610.462989] LDISKFS-fs (dm-0): mounted filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc r/w with ordered data mode. Quota mode: journalled. [17617.135335] Lustre: Evicted from MGS (at 192.168.206.108@tcp) after server handle changed from 0x0 to 0x242620d5754217a8 [17617.136694] Lustre: MGC192.168.206.108@tcp: Connection restored to 192.168.206.108@tcp (at 0@lo) [17617.136708] Lustre: Skipped 3 previous similar messages [17617.516101] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [17617.569910] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [17619.181662] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [17622.216436] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [17622.978333] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [17622.999858] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000402:10389 to 0x280000402:10433) [17623.005174] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000402:10356 to 0x2c0000402:10433) [17631.685175] Lustre: DEBUG MARKER: oleg608-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [17634.478984] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [17643.256670] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [17643.256705] Lustre: Skipped 3 previous similar messages [17643.257830] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [17646.981046] LDISKFS-fs (dm-0): unmounting filesystem 605ec502-4fd7-4a27-ad40-463ee1d00ebc. [17647.036503] Lustre: server umount lustre-MDT0000 complete [17648.358645] LustreError: 76235:0:(ldlm_lib.c:1092:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [17648.358677] LustreError: 76235:0:(ldlm_lib.c:1092:target_handle_connect()) Skipped 9 previous similar messages [17660.123176] LustreError: 9707:0:(ldlm_lockd.c:2587:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743511697 with bad export cookie 2604805535647799208 [17660.123706] LustreError: MGC192.168.206.108@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [17660.484836] LDISKFS-fs (dm-1): unmounting filesystem 64a4c258-2e5e-4000-b346-b7f7fec15802. [17661.207429] Lustre: server umount lustre-MDT0001 complete [17680.101449] Lustre: 4138:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743511701/real 1743511701] req@ffff88811ca81940 x1828186636741632/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743511717 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [17684.305393] LDISKFS-fs (dm-2): unmounting filesystem 9c5456c4-486c-4b08-b5f6-c89959e7019f. [17684.388324] Lustre: server umount lustre-OST0000 complete [17685.221664] Lustre: 4138:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743511706/real 1743511706] req@ffff88811ca85f40 x1828186636742144/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743511722 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [17685.221700] Lustre: 4138:0:(client.c:2340:ptlrpc_expire_one_request()) Skipped 1 previous similar message [17690.341387] Lustre: 4137:0:(client.c:2340:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743511712/real 1743511712] req@ffff88811ca80040 x1828186636742784/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743511728 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [17690.341423] Lustre: 4137:0:(client.c:2340:ptlrpc_expire_one_request()) Skipped 1 previous similar message [17695.461458] LDISKFS-fs (dm-3): unmounting filesystem 4f880528-4d9f-4d08-b344-8f3dda33f739. [17695.703793] Lustre: server umount lustre-OST0001 complete [17719.568132] Lustre: DEBUG MARKER: oleg608-server.virtnet: executing unload_modules_local [17725.248932] Key type lgssc unregistered [17725.918734] LNet: 147444:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [17726.955790] LNet: Removed LNI 192.168.206.108@tcp [17728.755983] Key type .llcrypt unregistered [17728.756037] Key type ._llcrypt unregistered