[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 799745318 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001008] APIC: Switch to symmetric I/O mode setup [ 0.003377] x2apic enabled [ 0.004010] Switched APIC routing to physical x2apic. [ 0.006012] kvm-guest: setup PV IPIs [ 0.010785] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.011000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.011019] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.012012] pid_max: default: 32768 minimum: 301 [ 0.015026] LSM: Security Framework initializing [ 0.016061] Yama: becoming mindful. [ 0.017049] SELinux: Initializing. [ 0.018118] *** VALIDATE selinux *** [ 0.035964] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.047108] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.048340] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.050094] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.051103] *** VALIDATE tmpfs *** [ 0.053877] *** VALIDATE proc *** [ 0.055680] *** VALIDATE cgroup *** [ 0.056010] *** VALIDATE cgroup2 *** [ 0.057250] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.058169] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.059011] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.060028] Spectre V2 : User space: Vulnerable [ 0.062008] Speculative Store Bypass: Vulnerable [ 0.068085] debug: unmapping init [mem 0xffffffff8e859000-0xffffffff8e860fff] [ 0.070398] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.071917] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.072020] ... version: 2 [ 0.073011] ... bit width: 48 [ 0.074008] ... generic registers: 4 [ 0.075009] ... value mask: 0000ffffffffffff [ 0.076011] ... max period: 00007fffffffffff [ 0.077012] ... fixed-purpose events: 3 [ 0.078008] ... event mask: 000000070000000f [ 0.079268] rcu: Hierarchical SRCU implementation. [ 0.081719] smp: Bringing up secondary CPUs ... [ 0.082692] x86: Booting SMP configuration: [ 0.083019] .... node #0, CPUs: #1 #2 #3 [ 0.095136] smp: Brought up 1 node, 4 CPUs [ 0.097012] smpboot: Max logical packages: 1 [ 0.098010] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.130657] node 0 deferred pages initialised in 30ms [ 0.134035] devtmpfs: initialized [ 0.135446] x86/mm: Memory block size: 128MB [ 0.138244] gcov: version magic: 0x41383552 [ 0.140347] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.141097] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.142309] pinctrl core: initialized pinctrl subsystem [ 0.143199] [ 0.143847] ************************************************************* [ 0.144023] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.145013] ** ** [ 0.146013] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.147012] ** ** [ 0.148013] ** This means that this kernel is built to expose internal ** [ 0.149014] ** IOMMU data structures, which may compromise security on ** [ 0.150018] ** your system. ** [ 0.151011] ** ** [ 0.152013] ** If you see this message and you are not debugging the ** [ 0.153015] ** kernel, report this immediately to your vendor! ** [ 0.154016] ** ** [ 0.155018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.156015] ************************************************************* [ 0.157970] NET: Registered protocol family 16 [ 0.158597] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.159075] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.160077] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.161838] cpuidle: using governor menu [ 0.162968] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.163721] PCI: Using configuration type 1 for base access [ 0.165195] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.177337] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.179015] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.184047] cryptd: max_cpu_qlen set to 1000 [ 0.187240] ACPI: Added _OSI(Module Device) [ 0.188013] ACPI: Added _OSI(Processor Device) [ 0.190014] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.192011] ACPI: Added _OSI(Processor Aggregator Device) [ 0.200190] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.209150] ACPI: Interpreter enabled [ 0.210141] ACPI: PM: (supports S0 S3 S4 S5) [ 0.211012] ACPI: Using IOAPIC for interrupt routing [ 0.212087] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.213677] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.230190] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.232045] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.235016] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.239078] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.246065] acpiphp: Slot [2] registered [ 0.248145] acpiphp: Slot [5] registered [ 0.250126] acpiphp: Slot [6] registered [ 0.251274] acpiphp: Slot [7] registered [ 0.253373] acpiphp: Slot [8] registered [ 0.255108] acpiphp: Slot [9] registered [ 0.257498] acpiphp: Slot [10] registered [ 0.259202] acpiphp: Slot [3] registered [ 0.262100] acpiphp: Slot [4] registered [ 0.263085] acpiphp: Slot [11] registered [ 0.265095] acpiphp: Slot [12] registered [ 0.267097] acpiphp: Slot [13] registered [ 0.269120] acpiphp: Slot [14] registered [ 0.271235] acpiphp: Slot [15] registered [ 0.273083] acpiphp: Slot [16] registered [ 0.275197] acpiphp: Slot [17] registered [ 0.276181] acpiphp: Slot [18] registered [ 0.278091] acpiphp: Slot [19] registered [ 0.280103] acpiphp: Slot [20] registered [ 0.282203] acpiphp: Slot [21] registered [ 0.284253] acpiphp: Slot [22] registered [ 0.286163] acpiphp: Slot [23] registered [ 0.288093] acpiphp: Slot [24] registered [ 0.289073] acpiphp: Slot [25] registered [ 0.290074] acpiphp: Slot [26] registered [ 0.291067] acpiphp: Slot [27] registered [ 0.292066] acpiphp: Slot [28] registered [ 0.293064] acpiphp: Slot [29] registered [ 0.295115] acpiphp: Slot [30] registered [ 0.296064] acpiphp: Slot [31] registered [ 0.297094] PCI host bridge to bus 0000:00 [ 0.299012] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.300023] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.302018] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.304017] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.306017] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.309024] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.312155] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.316062] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.318672] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.331010] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.337073] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.341020] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.344020] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.352020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.365000] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.366071] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.369038] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.374452] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.383032] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.407014] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.416014] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.422173] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.429019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.438016] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.489050] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.511290] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.519021] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.529017] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.534000] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.570920] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.594014] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.609016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.636029] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.663272] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.671014] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.724016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.806056] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.853267] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.858013] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.864016] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.877024] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.888412] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.892010] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.898036] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.909092] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.920000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.921508] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.923483] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.926406] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.928149] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.933126] iommu: Default domain type: Passthrough [ 0.938057] SCSI subsystem initialized [ 0.941336] ACPI: bus type USB registered [ 0.944191] usbcore: registered new interface driver usbfs [ 0.948116] usbcore: registered new interface driver hub [ 0.952188] usbcore: registered new device driver usb [ 0.957725] pps_core: LinuxPPS API ver. 1 registered [ 0.961015] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.968115] PTP clock support registered [ 0.972238] EDAC MC: Ver: 3.0.0 [ 0.976570] PCI: Using ACPI for IRQ routing [ 0.981850] NetLabel: Initializing [ 0.984182] NetLabel: domain hash size = 128 [ 0.987019] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.992126] NetLabel: unlabeled traffic allowed by default [ 0.996346] vgaarb: loaded [ 0.998797] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.003018] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.010222] clocksource: Switched to clocksource kvm-clock [ 1.190926] VFS: Disk quotas dquot_6.6.0 [ 1.193610] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.197727] *** VALIDATE ramfs *** [ 1.199830] *** VALIDATE hugetlbfs *** [ 1.202409] pnp: PnP ACPI init [ 1.205895] pnp: PnP ACPI: found 6 devices [ 1.226444] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.232290] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.235914] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.239585] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.243562] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.247545] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.251805] NET: Registered protocol family 2 [ 1.255145] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.262864] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.268923] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.276950] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.282695] TCP: Hash tables configured (established 65536 bind 65536) [ 1.287903] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.293774] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.298653] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.304491] NET: Registered protocol family 1 [ 1.308611] RPC: Registered named UNIX socket transport module. [ 1.312116] RPC: Registered udp transport module. [ 1.315088] RPC: Registered tcp transport module. [ 1.317935] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.321899] NET: Registered protocol family 44 [ 1.324570] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.328144] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.331565] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.334772] PCI: CLS 0 bytes, default 64 [ 1.337947] Unpacking initramfs... [ 3.591992] debug: unmapping init [mem 0xffff88e77cc54000-0xffff88e77ffbffff] [ 3.729685] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 3.736135] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 3.792638] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 4.647070] Initialise system trusted keyrings [ 4.648966] Key type blacklist registered [ 4.651792] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 4.721900] zbud: loaded [ 4.726697] *** VALIDATE nfs *** [ 4.727932] *** VALIDATE nfs4 *** [ 4.729356] pstore: using deflate compression [ 4.732822] Platform Keyring initialized [ 4.847695] NET: Registered protocol family 38 [ 4.849770] Key type asymmetric registered [ 4.852154] Asymmetric key parser 'x509' registered [ 4.854302] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 4.857956] io scheduler mq-deadline registered [ 4.860832] io scheduler kyber registered [ 4.862695] io scheduler bfq registered [ 4.864894] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 4.868399] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 4.871632] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 4.874876] ACPI: Power Button [PWRF] [ 4.881125] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 4.888150] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 4.908510] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 4.915898] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 4.929314] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 4.960239] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 5.045541] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 5.076850] Non-volatile memory driver v1.3 [ 5.078552] Linux agpgart interface v0.103 [ 5.124396] virtio_blk virtio1: [vda] 134032 512-byte logical blocks (68.6 MB/65.4 MiB) [ 5.127860] vda: detected capacity change from 0 to 68624384 [ 5.416485] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 5.421661] vdb: detected capacity change from 0 to 1073741824 [ 5.636543] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 5.646618] vdc: detected capacity change from 0 to 2621440000 [ 5.725103] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 5.727482] vdd: detected capacity change from 0 to 2621440000 [ 5.764582] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 5.773975] vde: detected capacity change from 0 to 4294967296 [ 5.839353] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 5.841972] vdf: detected capacity change from 0 to 4294967296 [ 5.978841] libphy: Fixed MDIO Bus: probed [ 5.985501] usbcore: registered new interface driver usbserial_generic [ 5.987540] usbserial: USB Serial support registered for generic [ 5.989443] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 5.993617] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 5.995013] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 5.997190] mousedev: PS/2 mouse device common for all mice [ 5.999795] rtc_cmos 00:05: RTC can wake from S4 [ 6.003773] rtc_cmos 00:05: registered as rtc0 [ 6.004862] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 6.005799] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 6.005833] intel_pstate: CPU model not supported [ 6.009936] hid: raw HID events driver (C) Jiri Kosina [ 6.010342] usbcore: registered new interface driver usbhid [ 6.019629] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 6.019809] usbhid: USB HID core driver [ 6.019946] drop_monitor: Initializing network drop monitor service [ 6.020566] Initializing XFRM netlink socket [ 6.025450] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 6.027977] NET: Registered protocol family 10 [ 6.037049] Segment Routing with IPv6 [ 6.042911] NET: Registered protocol family 17 [ 6.044767] mpls_gso: MPLS GSO support [ 6.050285] RAS: Correctable Errors collector initialized. [ 6.052550] AVX version of gcm_enc/dec engaged. [ 6.054291] AES CTR mode by8 optimization enabled [ 6.185786] sched_clock: Marking stable (6185545412, 0)->(8204136533, -2018591121) [ 6.193780] registered taskstats version 1 [ 6.196675] Loading compiled-in X.509 certificates [ 6.199436] zswap: loaded using pool lzo/zbud [ 6.234330] Key type big_key registered [ 6.248536] Key type encrypted registered [ 6.249675] ima: No TPM chip found, activating TPM-bypass! [ 6.251075] ima: Allocated hash algorithm: sha1 [ 6.252518] ima: No architecture policies found [ 6.254355] evm: Initialising EVM extended attributes: [ 6.256609] evm: security.selinux [ 6.257648] evm: security.ima [ 6.258781] evm: security.capability [ 6.259706] evm: HMAC attrs: 0x1 [ 6.262609] rtc_cmos 00:05: setting system clock to 2026-01-02 00:49:29 UTC (1767314969) [ 6.273781] debug: unmapping init [mem 0xffffffff8f803000-0xffffffff8f9fffff] [ 6.278272] debug: unmapping init [mem 0xffffffff8e582000-0xffffffff8e858fff] [ 6.294313] Write protecting the kernel read-only data: 28672k [ 6.300497] debug: unmapping init [mem 0xffffffff8cc03000-0xffffffff8cdfffff] [ 6.304335] debug: unmapping init [mem 0xffffffff8d514000-0xffffffff8d5fffff] [ 6.352864] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 6.366995] systemd[1]: Detected virtualization kvm. [ 6.369550] systemd[1]: Detected architecture x86-64. [ 6.371966] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 6.421472] systemd[1]: No hostname configured. [ 6.425256] systemd[1]: Set hostname to . [ 6.430052] random: systemd: uninitialized urandom read (16 bytes read) [ 6.434315] systemd[1]: Initializing machine ID from random generator. [ 6.613803] random: ln: uninitialized urandom read (6 bytes read) [ 6.933867] random: systemd: uninitialized urandom read (16 bytes read) [ 6.942569] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 6.960508] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 7.009953] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ OK ] Listening on udev Control Socket. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. [ 7.877589] urandom_read: 5 callbacks suppressed [ 7.877599] random: systemd: uninitialized urandom read (16 bytes read) Starting Create Volatile Files and Directories... [ 8.010767] random: systemd: uninitialized urandom read (16 bytes read) Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Slices. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Sockets. Starting Journal Service... [ OK ] Reached target Swap. [ OK ] Reached target Timers. Starting Setup Virtual Console... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 12.146371] device-mapper: uevent: version 1.0.3 [ 12.150959] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 14.486205] virtio_net virtio0 ens2: renamed from eth0 [ 14.534743] random: fast init done [ 14.683515] scsi host0: ata_piix [ 15.283751] scsi host1: ata_piix [ 15.287319] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 15.293063] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 19.859650] random: crng init done [ 23.532101] dracut-initqueue[584]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 26.413325] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 31.000445] printk: systemd: 26 output lines suppressed due to ratelimiting [ 31.438921] SELinux: Disabled at runtime. [ 31.516853] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 31.527656] systemd[1]: Detected virtualization kvm. [ 31.531512] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 32.625863] systemd[1]: initrd-switch-root.service: Succeeded. [ 32.630994] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 32.646023] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 32.649066] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 32.653859] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 32.664234] systemd[1]: Starting Journal Service... Starting Journal Service... [ 32.669600] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Stopped target Switch Root. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting Huge Pages File System... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Listening on Process Core Dump Socket. Mounting Kernel Debug File System... [ OK ] Started Dispatch Password Requests to Console Directory Watch. Starting Apply Kernel Variables... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Created slice system-getty.slice. [ OK ] Stopped target Initrd File Systems. [ OK ] Reached target RPC Port Mapper. Mounting POSIX Message Queue File System... [ OK ] Reached target rpc_pipefs.target. Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Stopped target Initrd Root File System. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on initctl Compatibility Named Pipe. [ 33.393347] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting Remount Root and Kernel File Systems... [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started udev Coldplug all Devices. [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 34.534896] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 36.814609] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 37.034713] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 37.899509] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 38.134327] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit) [** ] A start job is running for Configur…-only root support (9s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ ***] A start job is running for Configur…only root support (11s / no limit) [ **] A start job is running for Configur…only root support (11s / no limit)[ 44.431193] Key type dns_resolver registered [ *] A start job is running for Configur…only root support (12s / no limit) [ **] A start job is running for Configur…only root support (12s / no limit)[ 45.525791] NFS: Registering the id_resolver key type [ 45.533522] Key type id_resolver registered [ 45.536731] Key type id_legacy registered [ ***] A start job is running for Configur…only root support (13s / no limit) [ *** ] A start job is running for Configur…only root support (13s / no limit) [ *** ] A start job is running for Configur…only root support (14s / no limit) [*** ] A start job is running for Configur…only root support (14s / no limit) [ OK ] Started 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 Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... Starting Login Service... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started Login Service. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started OpenSSH server daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg314-server login: [ 100.610716] spl: loading out-of-tree module taints kernel. [ 106.716900] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 126.955868] Key type ._llcrypt registered [ 126.959462] Key type .llcrypt registered [ 127.076093] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_hostid [ 154.616627] hrtimer: interrupt took 3618642 ns [ 196.158287] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 197.609038] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 197.623557] alg: No test for adler32 (adler32-zlib) [ 198.940490] Lustre: Lustre: Build Version: 2.17.0_RC4_1_g3742a8b [ 199.738131] LNet: Added LNI 192.168.203.114@tcp [8/256/0/180] [ 201.441249] Key type lgssc registered [ 202.983498] Lustre: Echo OBD driver; http://www.lustre.org/ [ 221.576048] vdc: vdc1 vdc9 [ 235.353838] vde: vde1 vde9 [ 250.634791] vdf: vdf1 vdf9 [ 250.647957] vdf: vdf1 vdf9 [ 328.882082] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 348.183552] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 349.551205] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 349.938465] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 350.085809] Lustre: lustre-MDT0000: new disk, initializing [ 350.654483] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 350.717708] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 355.827429] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 363.218462] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 375.269900] Lustre: lustre-OST0000: new disk, initializing [ 375.273447] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 375.281913] Lustre: Skipped 1 previous similar message [ 375.355689] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 382.956133] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 386.003297] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 386.011906] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 386.327462] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 402.920177] Lustre: lustre-OST0001: new disk, initializing [ 402.932228] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 403.031780] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 409.406592] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 412.437499] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 412.447486] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 412.661176] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 421.074303] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 431.276220] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 443.719892] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing check_logdir /tmp/testlogs/ [ 450.368939] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing yml_node [ 458.710844] Lustre: DEBUG MARKER: Client: 2.17.0.RC4 [ 460.888217] Lustre: DEBUG MARKER: MDS: 2.17.0.RC4 [ 463.453765] Lustre: DEBUG MARKER: OSS: 2.17.0.RC4 [ 465.203480] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Thu Jan 1 19:57:06 EST 2026 [ 482.635252] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 483.894351] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 12a 9 [ 486.119419] Lustre: DEBUG MARKER: === sanity-quota: start setup 19:57:27 (1767315447) === [ 489.646472] Lustre: DEBUG MARKER: oleg314-client.virtnet: executing check_config_client /mnt/lustre [ 526.124087] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 529.858436] Lustre: 20166:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 533.968209] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 537.878830] Lustre: DEBUG MARKER: === sanity-quota: finish setup 19:58:19 (1767315499) === [ 588.184157] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 19:59:10 (1767315550) [ 641.258460] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 20:00:03 (1767315603) [ 655.935713] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 665.230994] Lustre: DEBUG MARKER: Write... [ 670.039823] Lustre: DEBUG MARKER: Write out of block quota ... [ 711.525756] Lustre: DEBUG MARKER: -------------------------------------- [ 713.579855] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 720.007292] Lustre: DEBUG MARKER: Write... [ 723.171173] Lustre: DEBUG MARKER: Write out of block quota ... [ 764.869403] Lustre: DEBUG MARKER: -------------------------------------- [ 766.630747] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 769.715977] Lustre: DEBUG MARKER: Write... [ 772.514216] Lustre: DEBUG MARKER: Write out of block quota ... [ 834.349541] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 20:03:15 (1767315795) [ 850.070628] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 866.227246] Lustre: DEBUG MARKER: Write... [ 869.006528] Lustre: DEBUG MARKER: Write out of block quota ... [ 908.568571] Lustre: DEBUG MARKER: -------------------------------------- [ 910.373272] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 917.099087] Lustre: DEBUG MARKER: Write... [ 919.190854] Lustre: DEBUG MARKER: Write out of block quota ... [ 961.029357] Lustre: DEBUG MARKER: -------------------------------------- [ 962.619537] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 965.900519] Lustre: DEBUG MARKER: Write... [ 969.073248] Lustre: DEBUG MARKER: Write out of block quota ... [ 1037.830427] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 20:06:39 (1767315999) [ 1053.875297] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 1075.591552] Lustre: DEBUG MARKER: Write... [ 1079.728682] Lustre: DEBUG MARKER: Write out of block quota ... [ 1175.738795] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 20:08:57 (1767316137) [ 1192.443353] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 1213.316553] Lustre: DEBUG MARKER: Write... [ 1215.789894] Lustre: DEBUG MARKER: Write out of block quota ... [ 1304.341922] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 20:11:05 (1767316265) [ 1321.761131] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 1334.578783] Lustre: DEBUG MARKER: Write... [ 1337.302743] Lustre: DEBUG MARKER: Write out of block quota ... [ 1347.452224] Lustre: DEBUG MARKER: Write... [ 1402.894362] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 20:12:44 (1767316364) [ 1418.128965] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1430.291867] Lustre: DEBUG MARKER: Write... [ 1433.114849] Lustre: DEBUG MARKER: Write out of block quota ... [ 1477.313306] Lustre: DEBUG MARKER: Write... [ 1479.690831] Lustre: DEBUG MARKER: Write out of block quota ... [ 1534.233076] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 20:14:55 (1767316495) [ 1550.664974] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 1563.230467] Lustre: DEBUG MARKER: Write... [ 1576.915914] Lustre: DEBUG MARKER: Write out of block quota ... [ 1658.333634] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 20:16:59 (1767316619) [ 1660.030660] Lustre: DEBUG MARKER: SKIP: sanity-quota test_1h need >= 2.13.57 and ldiskfs for fallocate [ 1661.695295] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 20:17:03 (1767316623) [ 1676.787995] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1689.904599] Lustre: DEBUG MARKER: Write... [ 1692.762558] Lustre: DEBUG MARKER: Write out of block quota ... [ 1729.445578] Lustre: DEBUG MARKER: Write... [ 1732.448168] Lustre: DEBUG MARKER: Write out of block quota ... [ 1743.876980] LustreError: 12762:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:15365 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 1788.365751] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 20:19:10 (1767316750) [ 1806.739325] Lustre: DEBUG MARKER: -------------------------------------- [ 1808.582243] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 2112.504543] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 2115.044988] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 20:24:36 (1767317076) [ 2204.123696] Lustre: DEBUG MARKER: Write after timer goes off [ 2205.917743] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2339.211753] Lustre: DEBUG MARKER: Write after timer goes off [ 2340.799371] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2473.261873] Lustre: DEBUG MARKER: Write after timer goes off [ 2474.997246] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2566.922513] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 20:32:08 (1767317528) [ 2662.445545] Lustre: DEBUG MARKER: Write after timer goes off [ 2664.488874] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2793.509460] Lustre: DEBUG MARKER: Write after timer goes off [ 2795.493306] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2927.494952] Lustre: DEBUG MARKER: Write after timer goes off [ 2929.210152] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3032.104582] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 20:39:53 (1767317993) [ 3132.400336] Lustre: DEBUG MARKER: Write after timer goes off [ 3134.238234] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3228.861339] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 3230.730812] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 20:43:12 (1767318192) [ 3247.597619] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 3374.640582] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 20:45:36 (1767318336) [ 3426.281304] Lustre: *** cfs_fail_loc=513, val=601*** [ 3426.884825] Lustre: *** cfs_fail_loc=513, val=601*** [ 3426.887175] Lustre: Skipped 6 previous similar messages [ 3427.095639] LustreError: 22616:0:(service.c:2319:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1853164264885248 [ 3428.320184] Lustre: *** cfs_fail_loc=513, val=601*** [ 3428.321916] Lustre: Skipped 13 previous similar messages [ 3431.846585] Lustre: *** cfs_fail_loc=513, val=601*** [ 3436.971802] Lustre: *** cfs_fail_loc=513, val=601*** [ 3436.978125] Lustre: Skipped 9 previous similar messages [ 3442.655301] Lustre: 14078:0:(service.c:1607:ptlrpc_at_send_early_reply()) @@@ Could not add any time (5/5), not sending early reply req@ffff88e6c2ad1880 x1853164198398336/t0(0) o4->ceeb431a-43d5-4103-b7a2-5e1070abf3cf@192.168.203.14@tcp:65/0 lens 488/448 e 1 to 0 dl 1767318410 ref 2 fl Interpret:/600/0 rc 0/0 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 3443.679201] Lustre: 42613:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767318390/real 1767318390] req@ffff88e7e770ad80 x1853164264885248/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1767318406 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_006.0' uid:0 gid:0 projid:4294967295 [ 3443.718070] 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 [ 3443.755925] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3443.771682] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3444.866184] LustreError: 22616:0:(service.c:2319:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1853164264889088 [ 3447.205239] Lustre: *** cfs_fail_loc=513, val=601*** [ 3447.209865] Lustre: Skipped 21 previous similar messages [ 3461.088871] Lustre: 42613:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767318408/real 1767318408] req@ffff88e7c7eddf80 x1853164264889088/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1767318424 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_006.0' uid:0 gid:0 projid:4294967295 [ 3461.128457] 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 [ 3461.150833] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3461.169135] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3463.206084] Lustre: *** cfs_fail_loc=513, val=601*** [ 3463.209978] Lustre: Skipped 36 previous similar messages [ 3463.243065] LustreError: 22616:0:(service.c:2319:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1853164264892672 [ 3479.520301] Lustre: 42613:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767318426/real 1767318426] req@ffff88e7c4f00a80 x1853164264892672/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1767318442 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_006.0' uid:0 gid:0 projid:4294967295 [ 3479.558838] 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 [ 3479.588099] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3479.604307] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3520.692672] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 20:48:01 (1767318481) [ 3547.868865] Lustre: Failing over lustre-OST0000 [ 3547.934169] LustreError: 68867:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3547.969612] Lustre: server umount lustre-OST0000 complete [ 3549.707664] LustreError: lustre-OST0000-osc-MDT0000: operation ost_setattr to node 0@lo failed: rc = -107 [ 3549.712508] 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 [ 3554.731996] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.14@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3554.755954] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 3556.323103] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3559.848837] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.14@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3563.599905] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3563.613365] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3564.969600] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3565.699985] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3565.700146] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3569.516401] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3577.542393] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3583.188787] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3589.133276] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3595.130831] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3602.322788] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3609.039983] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3638.331053] Lustre: Failing over lustre-OST0000 [ 3638.483093] LustreError: 72424:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3638.486472] LustreError: 72424:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 3638.504076] Lustre: server umount lustre-OST0000 complete [ 3640.295146] 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 [ 3640.303443] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3640.330651] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 3645.413566] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3654.176121] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3654.198212] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3656.194844] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3656.342219] Lustre: lustre-OST0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3656.344960] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3661.963746] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3670.124945] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3675.863103] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3683.564703] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3689.795433] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3695.317387] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3700.396474] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3733.720484] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 20:51:35 (1767318695) [ 3767.394310] Lustre: *** cfs_fail_loc=a02, val=0*** [ 3773.533481] LustreError: 6059:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -5, flags:0x8 qsd:lustre-OST0000 qtype:usr id:60000 enforced:1 granted: 1026 pending:0 waiting:0 req:1 usage: 2052 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 3773.559443] Lustre: Failing over lustre-OST0000 [ 3773.622088] LustreError: 77327:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3773.624634] LustreError: 77327:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 3773.689161] Lustre: server umount lustre-OST0000 complete [ 3774.439200] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 3774.448483] 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 [ 3774.457517] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3774.464798] LustreError: 14070:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 3787.351789] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3787.363258] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3788.938503] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3789.417205] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3789.417524] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3794.378164] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3802.349455] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3808.784190] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3815.259720] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3821.463563] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3827.203474] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3833.148139] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3880.596823] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 20:54:02 (1767318842) [ 3904.947947] LustreError: 81968:0:(qsd_reint.c:475:qsd_reint_main()) cfs_fail_timeout id a03 sleeping for 10000ms [ 3906.722634] Lustre: Failing over lustre-MDT0000 [ 3906.999747] LustreError: 82071:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 3907.004189] LustreError: 82071:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 3907.127184] Lustre: server umount lustre-MDT0000 complete [ 3912.187512] LustreError: 81973:0:(qsd_reint.c:475:qsd_reint_main()) cfs_fail_timeout interrupted [ 3912.195920] LustreError: 81973:0:(qsd_reint.c:475:qsd_reint_main()) Skipped 1 previous similar message [ 3923.569587] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3924.109058] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3924.333471] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3924.408605] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3924.492298] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3924.610040] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3924.649887] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:140 to 0x240000400:161) [ 3924.655271] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 3926.175127] Lustre: 6057:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767318873/real 1767318873] req@ffff88e7fc99b800 x1853164265238656/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767318889 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3929.523556] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3929.569730] LustreError: 6056:0:(ldlm_resource.c:981:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x2020000:0x0].0x0 (ffff88e7c3c3a900) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 3929.598788] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3931.615382] Lustre: 6057:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767318878/real 1767318878] req@ffff88e7e722b800 x1853164265239936/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767318894 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3931.642597] Lustre: 6057:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 3937.960956] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 4028.487991] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 4033.936746] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 4039.261554] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 4045.703387] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 4052.137916] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 4089.033966] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 20:57:30 (1767319050) [ 4116.306244] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 4122.060666] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 4169.795347] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 20:58:51 (1767319131) [ 4171.484818] Lustre: DEBUG MARKER: SKIP: sanity-quota test_7e needs >= 2 MDTs [ 4173.736161] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 20:58:55 (1767319135) [ 4374.748332] Lustre: DEBUG MARKER: SKIP: sanity-quota test_9 skipping SLOW test 9 [ 4376.507493] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 21:02:18 (1767319338) [ 4424.831415] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 21:03:06 (1767319386) [ 4475.844426] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12a skipping SLOW test 12a [ 4477.674209] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 21:03:59 (1767319439) [ 4479.321377] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12b needs >= 2 MDTs [ 4481.183487] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 21:04:02 (1767319442) [ 4543.428155] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 21:05:04 (1767319504) [ 4570.030279] Lustre: Failing over lustre-OST0000 [ 4570.136128] LustreError: 95683:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 4570.140417] LustreError: 95683:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 4570.167730] Lustre: server umount lustre-OST0000 complete [ 4574.650986] LustreError: 90472:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.14@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4574.666732] LustreError: 90472:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 4574.688062] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 4574.708655] 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 [ 4574.726936] Lustre: Skipped 1 previous similar message [ 4579.753215] LustreError: 90472:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.14@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4579.781977] LustreError: 90472:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 4584.879963] LustreError: 90530:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.14@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4584.911891] LustreError: 90530:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 4588.341988] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4588.371082] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4589.997935] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4590.288544] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4590.289459] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4590.320319] Lustre: Skipped 1 previous similar message [ 4596.025913] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4639.474089] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 21:06:41 (1767319601) [ 4664.775831] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 21:07:06 (1767319626) [ 4690.707270] Lustre: lustre-OST0000: Client ceeb431a-43d5-4103-b7a2-5e1070abf3cf (at 192.168.203.14@tcp) reconnecting [ 4717.319330] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 21:07:58 (1767319678) [ 4719.028985] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 4721.698469] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 21:08:02 (1767319682) [ 4746.018033] Lustre: *** cfs_fail_loc=a04, val=37*** [ 4746.026481] LustreError: 14077:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 4747.060051] Lustre: *** cfs_fail_loc=a04, val=37*** [ 4747.065352] LustreError: 14077:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1024 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 4749.200728] Lustre: *** cfs_fail_loc=a04, val=37*** [ 4749.203177] LustreError: 14077:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1024 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 4805.769290] Lustre: *** cfs_fail_loc=a04, val=11*** [ 4866.612539] Lustre: *** cfs_fail_loc=a04, val=110*** [ 4866.620668] Lustre: Skipped 2 previous similar messages [ 4927.767964] Lustre: *** cfs_fail_loc=a04, val=107*** [ 4927.775629] Lustre: Skipped 3 previous similar messages [ 4931.100546] 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 [ 4931.112566] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 4931.115539] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5022.057934] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 21:13:03 (1767319983) [ 5039.354163] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5044.179986] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 5047.642735] LustreError: 106217:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5048.635290] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5050.588139] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5052.809801] Lustre: Failing over lustre-MDT0000 [ 5052.943669] LustreError: lustre-MDT0000-lwp-OST0000: operation quota_acquire to node 0@lo failed: rc = -107 [ 5052.953628] 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 [ 5052.972195] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5053.065066] LustreError: 106411:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 5053.071584] LustreError: 106411:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 5055.140906] LustreError: 106411:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 5055.159382] LustreError: 106411:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 5055.291479] Lustre: server umount lustre-MDT0000 complete [ 5073.774969] Lustre: 6057:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767320020/real 1767320020] req@ffff88e7e7e5ce00 x1853164266442880/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767320036 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5073.829415] Lustre: 6057:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 5073.839984] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5073.858120] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5078.502293] Lustre: 6057:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767320025/real 1767320025] req@ffff88e7c719df80 x1853164266443520/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767320041 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5078.540827] Lustre: 6057:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5082.911134] Lustre: 6060:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767320030/real 1767320030] req@ffff88e801ae4700 x1853164266444032/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767320046 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5084.063846] LustreError: 6056:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff88e7e7709880 x1853164266445696/t0(0) o250->MGC192.168.203.114@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 projid:4294967295 [ 5084.796550] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5084.847318] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5088.735389] Lustre: 6059:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767320035/real 1767320035] req@ffff88e7c719d500 x1853164266444544/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767320051 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5089.979961] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5091.818902] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5097.895848] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5098.062651] LustreError: 107218:0:(tgt_handler.c:526:tgt_filter_recovery_request()) @@@ not permitted during recovery req@ffff88e7e7709180 x1853164266457216/t0(0) o601->lustre-MDT0000-lwp-OST0000_UUID@0@lo:217/0 lens 336/0 e 0 to 0 dl 1767320072 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'qsd_reint_0.lus.0' uid:0 gid:0 projid:4294967295 [ 5098.083428] LustreError: lustre-MDT0000-lwp-OST0000: operation quota_acquire to node 0@lo failed: rc = -11 [ 5098.142299] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5098.233138] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:646 to 0x280000400:673) [ 5098.234879] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:649 to 0x240000400:673) [ 5102.513447] Lustre: DEBUG MARKER: oleg314-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5104.083625] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5120.350742] Lustre: DEBUG MARKER: (dd_pid=95216, time=9, timeout=600) [ 5168.181444] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5173.258978] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 5176.692836] LustreError: 109141:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5177.488028] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5179.419401] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5181.637272] Lustre: Failing over lustre-MDT0000 [ 5181.866258] LustreError: lustre-MDT0000-lwp-OST0000: operation quota_acquire to node 0@lo failed: rc = -107 [ 5181.878722] 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 [ 5181.891677] LustreError: 109336:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 5181.900291] LustreError: 109336:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 5181.917741] LustreError: 107215:0:(ldlm_lib.c:1179: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. [ 5181.946186] LustreError: 107215:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 5182.121632] Lustre: server umount lustre-MDT0000 complete [ 5202.399208] Lustre: 6059:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767320149/real 1767320149] req@ffff88e7f7fca680 x1853164266483456/t0(0) o400->MGC192.168.203.114@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1767320165 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5202.437383] Lustre: 6059:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5202.442339] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5212.639631] LustreError: 6056:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff88e6d4beaa00 x1853164266486400/t0(0) o250->MGC192.168.203.114@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 projid:4294967295 [ 5213.254451] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5213.300779] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5218.459486] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5221.282820] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5221.285342] Lustre: Skipped 1 previous similar message [ 5225.895552] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5226.077061] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5226.149537] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:675 to 0x240000400:705) [ 5226.152460] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:646 to 0x280000400:705) [ 5229.724763] Lustre: DEBUG MARKER: oleg314-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5231.471548] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5249.946845] Lustre: DEBUG MARKER: (dd_pid=97544, time=11, timeout=600) [ 5304.270988] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 21:17:45 (1767320265) [ 5324.887867] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 5326.583991] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:2). [ 5331.627619] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 5333.342804] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:2). [ 5362.979927] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 21:18:44 (1767320324) [ 5383.808501] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 5400.077970] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 5401.663155] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 5403.394991] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 5405.920734] Lustre: DEBUG MARKER: Set quota for 1 times [ 5409.550602] Lustre: DEBUG MARKER: Set quota for 2 times [ 5413.157659] Lustre: DEBUG MARKER: Set quota for 3 times [ 5417.033331] Lustre: DEBUG MARKER: Set quota for 4 times [ 5420.372627] Lustre: DEBUG MARKER: Set quota for 5 times [ 5423.961523] Lustre: DEBUG MARKER: Set quota for 6 times [ 5427.965694] Lustre: DEBUG MARKER: Set quota for 7 times [ 5431.967697] Lustre: DEBUG MARKER: Set quota for 8 times [ 5492.581484] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 21:20:53 (1767320453) [ 5506.364683] LustreError: 115792:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 5506.387357] LustreError: 115792:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 5506.557447] Lustre: server umount lustre-MDT0000 complete [ 5514.418776] LustreError: 12747:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767320477 with bad export cookie 5064264606007754850 [ 5514.427472] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5523.983082] LustreError: 116188:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 5523.990890] LustreError: 116188:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 5524.017585] Lustre: server umount lustre-OST0000 complete [ 5525.472529] Lustre: 6060:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767320472/real 1767320472] req@ffff88e7c600c000 x1853164266603008/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767320488 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5525.537975] Lustre: 6060:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 5525.568718] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5525.577576] Lustre: Skipped 1 previous similar message [ 5528.820711] Lustre: server umount lustre-OST0001 complete [ 5554.802668] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 5571.874186] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5576.850071] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5583.350715] Lustre: 118773:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5594.958214] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5595.960707] LustreError: 119335:0:(ldlm_lib.c:1179: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. [ 5596.006887] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:707 to 0x240000400:737) [ 5602.129789] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5616.016174] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5617.892926] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:708 to 0x280000400:737) [ 5623.998816] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5632.282362] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5635.637646] Lustre: 121053:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5658.487392] LustreError: 121760:0:(obd_class.h:479:obd_check_dev()) Device 9 not setup [ 5658.492961] LustreError: 121760:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 5658.604729] Lustre: server umount lustre-MDT0000 complete [ 5667.312156] LustreError: 118192:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767320630 with bad export cookie 5064264606007762144 [ 5667.331440] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5677.704880] Lustre: server umount lustre-OST0000 complete [ 5678.566142] Lustre: 6059:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767320625/real 1767320625] req@ffff88e6d6639500 x1853164266648960/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767320641 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5678.600321] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5682.919475] Lustre: server umount lustre-OST0001 complete [ 5703.018974] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 5719.050427] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5723.565620] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5729.021761] Lustre: 124735:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5738.502086] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5744.559344] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5744.610418] LustreError: 125304:0:(ldlm_lib.c:1179: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. [ 5744.636550] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:707 to 0x240000400:769) [ 5744.636976] LustreError: 125304:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 5757.859040] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:708 to 0x280000400:769) [ 5762.904448] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5770.757474] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5774.413665] Lustre: 127012:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5791.055200] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 21:25:52 (1767320752) [ 5792.905519] Lustre: DEBUG MARKER: SKIP: sanity-quota test_23 Overwrite in place is not guaranteed to be space neutral on ZFS [ 5795.033336] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 21:25:56 (1767320756) [ 5844.812860] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 21:26:46 (1767320806) [ 5891.347249] Lustre: DEBUG MARKER: Write... [ 5893.588501] Lustre: DEBUG MARKER: Write out of block quota ... [ 5945.365676] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 21:28:27 (1767320907) [ 5951.314243] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 21:28:33 (1767320913) [ 5960.717543] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 21:28:42 (1767320922) [ 5968.264276] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 21:28:50 (1767320930) [ 5974.081615] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 21:28:56 (1767320936) [ 6031.027886] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 6152.741992] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 6306.177473] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 21:34:27 (1767321267) [ 6354.759913] Lustre: DEBUG MARKER: Restart... [ 6358.467429] LustreError: 139660:0:(obd_class.h:479:obd_check_dev()) Device 9 not setup [ 6358.472234] LustreError: 139660:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 6360.552164] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 6360.576473] LustreError: 124176:0:(ldlm_lib.c:1179: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. [ 6360.605014] LustreError: 124176:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 6360.681550] Lustre: server umount lustre-MDT0000 complete [ 6368.456017] LustreError: 124161:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767321331 with bad export cookie 5064264606007763670 [ 6368.461481] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6368.467053] LustreError: 124161:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 6368.540446] LustreError: 140059:0:(obd_class.h:479:obd_check_dev()) Device 14 not setup [ 6368.545522] LustreError: 140059:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 6368.567115] Lustre: server umount lustre-OST0000 complete [ 6372.747749] Lustre: server umount lustre-OST0001 complete [ 6391.973392] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 6406.305830] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6406.309109] Lustre: Skipped 1 previous similar message [ 6410.320455] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6414.506470] Lustre: 142630:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 6422.607690] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6427.797842] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6431.800194] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:779 to 0x240000400:801) [ 6438.308966] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 6439.863855] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:777 to 0x280000400:801) [ 6444.538759] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6452.221779] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6455.484460] Lustre: 144897:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 6514.978403] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 21:37:56 (1767321476) [ 6583.322047] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 21:39:04 (1767321544) [ 7933.229454] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 22:01:35 (1767322895) [ 7943.668627] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 7943.677849] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7943.686045] Lustre: Skipped 2 previous similar messages [ 7943.691784] Lustre: Skipped 1 previous similar message [ 7948.768339] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7948.773259] Lustre: Skipped 1 previous similar message [ 7949.950141] LustreError: 149895:0:(obd_class.h:479:obd_check_dev()) Device 9 not setup [ 7949.957270] LustreError: 149895:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 7950.049146] Lustre: server umount lustre-MDT0000 complete [ 7955.350582] LustreError: 148420:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767322918 with bad export cookie 5064264606007770138 [ 7955.361804] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7955.444092] LustreError: 150294:0:(obd_class.h:479:obd_check_dev()) Device 14 not setup [ 7955.451166] LustreError: 150294:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 7955.488904] Lustre: server umount lustre-OST0000 complete [ 7958.587212] LustreError: 150545:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 7958.590021] LustreError: 150545:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 7958.667268] Lustre: server umount lustre-OST0001 complete [ 7974.543413] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 7985.898756] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7989.155109] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7993.327663] Lustre: 152880:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 8000.454360] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 8004.657622] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8010.657738] LustreError: 153444:0:(ldlm_lib.c:1179: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. [ 8010.667645] LustreError: 153444:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 8010.678469] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5803 to 0x240000400:5825) [ 8011.436830] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 8013.302724] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5803 to 0x280000400:5825) [ 8014.924622] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8019.891558] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8022.381833] Lustre: 155153:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 8053.719686] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 22:03:36 (1767323016) [ 8084.224796] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 22:04:06 (1767323046) [ 8114.562815] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 22:04:36 (1767323076) [ 8115.824711] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40c needs >= 2 MDTs [ 8117.173196] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 22:04:39 (1767323079) [ 8118.299338] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40d needs >= 2 MDTs [ 8119.620749] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 22:04:41 (1767323081) [ 8182.934719] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 22:05:44 (1767323144) [ 8218.633815] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 22:06:20 (1767323180) [ 8285.041340] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 22:07:27 (1767323247) [ 8293.045783] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8293.051822] Lustre: Skipped 3 previous similar messages [ 8295.061176] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8295.063620] Lustre: Skipped 161 previous similar messages [ 8299.078690] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8299.082919] Lustre: Skipped 305 previous similar messages [ 8307.084833] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8307.088370] Lustre: Skipped 597 previous similar messages [ 8323.099253] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8323.101908] Lustre: Skipped 1233 previous similar messages [ 8355.106826] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8355.109894] Lustre: Skipped 2211 previous similar messages [ 8728.548585] 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 [ 8728.558807] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8728.560985] Lustre: Skipped 1 previous similar message [ 8729.825504] LustreError: 164114:0:(obd_class.h:479:obd_check_dev()) Device 9 not setup [ 8729.830723] LustreError: 164114:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 8729.913409] Lustre: server umount lustre-MDT0000 complete [ 8733.705349] LustreError: 152309:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767323696 with bad export cookie 5064264606009542328 [ 8733.713328] LustreError: 152309:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 8733.716390] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8733.877096] LustreError: 164515:0:(obd_class.h:479:obd_check_dev()) Device 14 not setup [ 8733.880947] LustreError: 164515:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 8733.890531] Lustre: server umount lustre-OST0000 complete [ 8736.369387] LustreError: 164765:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 8736.371848] LustreError: 164765:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 8736.418329] Lustre: server umount lustre-OST0001 complete [ 8741.697554] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_hostid [ 8745.723740] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 8756.497304] vdc: vdc1 vdc9 [ 8763.730920] vde: vde1 vde9 [ 8771.007794] vdf: vdf1 vdf9 [ 8780.018989] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [ 8786.899428] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 8787.011665] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 8787.058319] Lustre: lustre-MDT0000: new disk, initializing [ 8787.205910] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8787.232711] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 8789.271468] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8793.699970] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 8798.016369] Lustre: lustre-OST0000: new disk, initializing [ 8798.020201] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 8798.023035] Lustre: Skipped 1 previous similar message [ 8798.079382] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 8799.136047] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 8799.140144] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 8799.180987] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 8800.707603] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8807.466836] Lustre: lustre-OST0001: new disk, initializing [ 8807.469239] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 8807.501546] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 8809.006892] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 8809.010248] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 8809.056777] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 8810.277421] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8815.655048] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8817.271510] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 8843.767339] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 22:16:46 (1767323806) [ 8846.756783] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 22:16:49 (1767323809) [ 8874.620089] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 22:17:17 (1767323837) [ 8910.734588] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 22:17:53 (1767323873) [ 8925.405671] Lustre: DEBUG MARKER: rename directory return 255 [ 8951.732448] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 22:18:34 (1767323914) [ 8970.124520] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 22:18:52 (1767323932) [ 8994.798633] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 22:19:17 (1767323957) [ 9059.396960] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 22:20:21 (1767324021) [ 9080.455859] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 22:20:42 (1767324042) [ 9110.734650] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 22:21:13 (1767324073) [ 9197.353089] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 22:22:39 (1767324159) [ 9197.989755] Lustre: DEBUG MARKER: SKIP: sanity-quota test_59 ldiskfs only test [ 9198.737968] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 22:22:41 (1767324161) [ 9238.118674] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [ 9238.833039] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 22:23:21 (1767324201) [ 9257.074668] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [ 9257.806622] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 22:23:40 (1767324220) [ 9289.992874] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [ 9290.768731] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 22:24:13 (1767324253) [ 9319.870379] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 22:24:42 (1767324282) [ 9320.492834] Lustre: DEBUG MARKER: SKIP: sanity-quota test_67 ZFS grants some block space together with inode [ 9321.234595] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 22:24:43 (1767324283) [ 9337.479399] LustreError: 188635:0:(mgs_handler.c:1067:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [ 9363.851105] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 22:25:26 (1767324326) [ 9380.357172] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 9381.089776] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 9467.903739] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 22:27:10 (1767324430) [ 9495.949727] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 22:27:38 (1767324458) [ 9514.157628] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 22:27:56 (1767324476) [ 9514.743247] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71a ZFS grants some block space together with inode [ 9515.348155] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 22:27:58 (1767324478) [ 9515.876187] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71b ZFS grants some block space together with inode [ 9516.515357] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 22:27:59 (1767324479) [ 9525.542676] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [ 9533.746971] Lustre: DEBUG MARKER: Write... [ 9534.875465] Lustre: DEBUG MARKER: Write out of block quota ... [ 9570.537170] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 22:28:53 (1767324533) [ 9585.546806] Lustre: DEBUG MARKER: set to use default quota [ 9586.192589] Lustre: DEBUG MARKER: set default quota [ 9586.937141] Lustre: DEBUG MARKER: get default quota [ 9588.818130] Lustre: DEBUG MARKER: Test not out of quota [ 9590.462382] Lustre: DEBUG MARKER: Test out of quota [ 9594.442473] Lustre: DEBUG MARKER: Increase default quota [ 9604.237872] Lustre: DEBUG MARKER: Set quota to override default quota [ 9604.256551] LustreError: 172624:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:20480 soft:20480 granted:45063 time:1767929367 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 9608.181259] Lustre: DEBUG MARKER: Set to use default quota again [ 9618.800690] Lustre: DEBUG MARKER: Cleanup [ 9668.047499] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 22:30:30 (1767324630) [ 9681.287471] Lustre: DEBUG MARKER: set default quota for qpool1 [ 9681.919260] Lustre: DEBUG MARKER: Write from user that hasn't lqe [ 9709.487376] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 22:31:12 (1767324672) [ 9754.855685] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 22:31:57 (1767324717) [ 9793.870441] Lustre: DEBUG MARKER: Write... [ 9794.985388] Lustre: DEBUG MARKER: Write out of block quota ... [ 9857.925232] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 22:33:40 (1767324820) [ 9888.418105] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 22:34:11 (1767324851) [ 9890.927913] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 22:34:13 (1767324853) [ 9891.472151] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78A need >= 2.13.57 and ldiskfs for fallocate [ 9892.055507] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 22:34:14 (1767324854) [ 9892.640301] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78a need >= 2.13.57 and ldiskfs for fallocate [ 9893.227817] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 22:34:15 (1767324855) [ 9902.670650] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 22:34:25 (1767324865) [ 9903.232586] Lustre: DEBUG MARKER: SKIP: sanity-quota test_80 ZFS grants some block space together with inode [ 9903.889668] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 22:34:26 (1767324866) [ 9912.448729] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 9917.233794] LustreError: 210432:0:(qmt_pool.c:1295:qmt_pool_recalc()) cfs_fail_timeout id a07 sleeping for 10000ms [ 9917.236602] LustreError: 210432:0:(qmt_pool.c:1295:qmt_pool_recalc()) Skipped 5 previous similar messages [ 9919.402841] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.14@tcp (stopping) [ 9919.967995] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 9919.968391] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 9919.973293] Lustre: Skipped 2 previous similar messages [ 9924.516454] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.14@tcp (stopping) [ 9924.519468] Lustre: Skipped 1 previous similar message [ 9927.303064] LustreError: 210432:0:(qmt_pool.c:1295:qmt_pool_recalc()) cfs_fail_timeout id a07 awake [ 9927.365881] LustreError: 210533:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 9927.368020] LustreError: 210533:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 9927.406616] Lustre: server umount lustre-MDT0000 complete [ 9931.872857] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 9932.037677] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 9932.073514] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:27 to 0x240000400:65) [ 9932.073978] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:27 to 0x280000400:65) [ 9933.419682] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9950.432985] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 9950.437979] Lustre: Skipped 1 previous similar message [ 9965.571784] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 22:35:28 (1767324928) [ 9982.481779] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 22:35:45 (1767324945) [ 9998.930475] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 22:36:01 (1767324961) [10023.386199] Lustre: *** cfs_fail_loc=a08, val=0*** [10023.387430] Lustre: Skipped 3487 previous similar messages [10023.389398] Lustre: *** cfs_fail_loc=a08, val=0*** [10066.338844] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 22:37:09 (1767325029) [10120.239810] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 22:38:02 (1767325082) [10147.754790] LustreError: 217188:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:65536 time:1767929910 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [10198.614742] LustreError: 211253:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:65536 time:1767929961 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [10252.404946] LustreError: 212078:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:1000 enforced:1 hard:2048 soft:2048 granted:65536 time:1767930015 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [10299.479921] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 22:41:02 (1767325262) [10305.960152] Lustre: *** cfs_fail_loc=a09, val=0*** [10329.567798] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [10329.568298] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10329.573143] Lustre: Skipped 1 previous similar message [10329.575851] Lustre: Skipped 3 previous similar messages [10334.412041] LustreError: 219510:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [10334.414149] LustreError: 219510:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [10334.448534] Lustre: server umount lustre-MDT0000 complete [10338.413069] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10338.570728] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10338.604665] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:68 to 0x240000400:97) [10338.604729] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:27 to 0x280000400:97) [10339.858405] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10348.834119] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [10348.836466] Lustre: Skipped 1 previous similar message [10362.191757] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 22:42:04 (1767325324) [10362.714070] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [10363.270772] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 22:42:05 (1767325325) [10369.993554] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 22:42:12 (1767325332) [10394.141791] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 22:42:36 (1767325356) [10420.363744] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 22:43:03 (1767325383) [10434.837222] LustreError: 223691:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [10434.839407] LustreError: 223691:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [10434.877729] Lustre: server umount lustre-MDT0000 complete [10437.509919] LustreError: 174937:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767325400 with bad export cookie 5064264606011046320 [10437.515921] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10449.887725] LustreError: 224094:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff88e7d0d5b480 x1853164275963904/t0(0) o101->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 456/496 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'qsd_reint_0.lus.0' uid:0 gid:0 projid:4294967295 [10449.894780] LustreError: 224094:0:(qsd_reint.c:38:qsd_reint_completion()) lustre-OST0000: failed to enqueue global quota lock, glb fid:[0x200000006:0x20000:0x0], rc:-5 [10449.898439] LustreError: 224094:0:(qsd_reint.c:38:qsd_reint_completion()) Skipped 2 previous similar messages [10451.935339] Lustre: 6059:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767325399/real 1767325399] req@ffff88e7fe150000 x1853164275962880/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1767325415 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [10451.945641] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [10452.909858] LustreError: 224089:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [10452.912241] LustreError: 224089:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [10452.920639] Lustre: server umount lustre-OST0000 complete [10454.475097] LustreError: 224098:0:(qsd_reint.c:38:qsd_reint_completion()) lustre-OST0001: failed to enqueue global quota lock, glb fid:[0x200000006:0x1020000:0x0], rc:-5 [10454.479147] LustreError: 224098:0:(qsd_reint.c:38:qsd_reint_completion()) Skipped 2 previous similar messages [10456.529424] Lustre: server umount lustre-OST0001 complete [10459.858601] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_hostid [10462.102462] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [10468.714321] vdc: vdc1 vdc9 [10473.931989] vde: vde1 vde9 [10478.827522] vdf: vdf1 vdf9 [10478.833125] vdf: vdf1 vdf9 [10478.841667] vdf: vdf1 vdf9 [10484.415283] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [10484.492327] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [10484.528457] Lustre: lustre-MDT0000: new disk, initializing [10484.614715] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10484.634026] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [10486.010047] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10489.059615] Lustre: DEBUG MARKER: oleg314-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [10492.100707] Lustre: lustre-OST0000: new disk, initializing [10492.102329] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [10492.103729] Lustre: Skipped 1 previous similar message [10492.123466] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [10493.767823] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [10493.770557] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [10493.799195] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [10494.038906] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10497.016311] Lustre: DEBUG MARKER: oleg314-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [10499.835050] Lustre: lustre-OST0001: new disk, initializing [10499.836634] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [10499.860487] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [10501.187145] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [10501.189781] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [10501.221440] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [10501.798810] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10504.946743] Lustre: DEBUG MARKER: oleg314-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid [10511.327444] 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 [10511.327804] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10511.330753] Lustre: Skipped 1 previous similar message [10511.335917] Lustre: Skipped 2 previous similar messages [10516.758338] LustreError: 231505:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [10516.761078] LustreError: 231505:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [10516.802500] Lustre: server umount lustre-MDT0000 complete [10521.750632] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10521.882822] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10523.182614] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10524.988483] Lustre: DEBUG MARKER: oleg314-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [10535.893539] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 10 sec [10541.538936] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [10541.541805] Lustre: Skipped 1 previous similar message [10548.366158] LustreError: 232995:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [10548.369302] LustreError: 232995:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [10548.401556] Lustre: server umount lustre-MDT0000 complete [10551.046519] LustreError: 229449:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767325514 with bad export cookie 5064264606011049078 [10551.049923] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10561.527532] Lustre: server umount lustre-OST0000 complete [10573.235571] LustreError: 233643:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [10573.238128] LustreError: 233643:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [10573.264310] Lustre: server umount lustre-OST0001 complete [10581.716959] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_hostid [10583.826291] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [10590.399327] vdc: vdc1 vdc9 [10595.058385] vde: vde1 vde9 [10599.815347] vdf: vdf1 vdf9 [10606.205898] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing load_modules_local [10611.262794] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [10611.339897] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [10611.374146] Lustre: lustre-MDT0000: new disk, initializing [10611.465689] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10611.483469] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [10612.772483] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10615.797458] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [10619.009500] Lustre: lustre-OST0000: new disk, initializing [10619.011699] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [10619.014190] Lustre: Skipped 1 previous similar message [10620.828095] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [10620.831064] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [10620.861609] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [10621.020641] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10627.214321] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [10627.245163] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [10628.087573] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10632.408919] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10633.572969] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [10641.101319] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 22:46:43 (1767325603) [10648.677456] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 22:46:51 (1767325611) [10662.931768] Lustre: *** cfs_fail_loc=170c, val=0*** [10696.010075] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 22:47:38 (1767325658) [10709.471941] 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 [10709.472723] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10709.483414] Lustre: Skipped 1 previous similar message [10709.488180] Lustre: Skipped 4 previous similar messages [10714.704827] LustreError: 245829:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [10714.708086] LustreError: 245829:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [10714.735861] Lustre: server umount lustre-MDT0000 complete [10718.797996] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10718.937461] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10718.940182] Lustre: Skipped 2 previous similar messages [10718.966028] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3 to 0x240000400:33) [10720.266473] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10724.322090] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [10724.324885] Lustre: Skipped 1 previous similar message [10734.560033] 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 [10734.560351] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10734.565473] Lustre: Skipped 1 previous similar message [10734.566896] Lustre: Skipped 3 previous similar messages [10739.817301] Lustre: server umount lustre-MDT0000 complete [10743.815227] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10743.979364] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3 to 0x240000400:65) [10745.196991] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10757.716912] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 22:48:40 (1767325720) [10765.850065] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 22:48:48 (1767325728) [10785.932571] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 22:49:08 (1767325748) [10786.434978] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 the test in only needed to run on LDiskFS [10788.456806] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 10323 sec ======== 22:49:11 (1767325751) [10788.944132] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 22:49:11 (1767325751) === [10789.947262] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 22:49:12 (1767325752) === [10792.967263] LustreError: 251147:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [10792.969061] LustreError: 251147:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [10792.995497] Lustre: server umount lustre-MDT0000 complete [10795.333641] LustreError: 239368:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1767325758 with bad export cookie 5064264606011052172 [10795.337228] LustreError: MGC192.168.203.114@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10805.751184] Lustre: server umount lustre-OST0000 complete [10817.483285] Lustre: server umount lustre-OST0001 complete [10822.497604] Lustre: DEBUG MARKER: oleg314-server.virtnet: executing unload_modules_local [10823.519713] Key type lgssc unregistered [10823.638342] LNet: 252571:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10823.641759] LNetError: 252571:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [10823.652325] LNet: Removed LNI 192.168.203.114@tcp [10823.921139] Key type .llcrypt unregistered [10823.922393] Key type ._llcrypt unregistered