[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffd9fff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffda000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 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 557922236 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2464 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2300 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022C0 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2374 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE2404 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE243C 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2300-0xbffe2373] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22ff] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2374-0xbffe2403] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe2404-0xbffe243b] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe243c-0xbffe2463] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059618 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2835896K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.003143] x2apic enabled [ 0.004006] Switched APIC routing to physical x2apic. [ 0.005008] kvm-guest: setup PV IPIs [ 0.007995] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009014] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010008] pid_max: default: 32768 minimum: 301 [ 0.011233] LSM: Security Framework initializing [ 0.012062] Yama: becoming mindful. [ 0.013041] SELinux: Initializing. [ 0.014056] *** VALIDATE selinux *** [ 0.026566] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.033481] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.034246] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.036146] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.037196] *** VALIDATE tmpfs *** [ 0.039579] *** VALIDATE proc *** [ 0.041440] *** VALIDATE cgroup *** [ 0.042011] *** VALIDATE cgroup2 *** [ 0.043377] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.044232] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.045010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.046043] Spectre V2 : User space: Vulnerable [ 0.047028] Speculative Store Bypass: Vulnerable [ 0.051413] debug: unmapping init [mem 0xffffffffb8859000-0xffffffffb8860fff] [ 0.054234] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.055913] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.056028] ... version: 2 [ 0.057009] ... bit width: 48 [ 0.058008] ... generic registers: 4 [ 0.059022] ... value mask: 0000ffffffffffff [ 0.060014] ... max period: 00007fffffffffff [ 0.061011] ... fixed-purpose events: 3 [ 0.062010] ... event mask: 000000070000000f [ 0.063327] rcu: Hierarchical SRCU implementation. [ 0.065850] smp: Bringing up secondary CPUs ... [ 0.066851] x86: Booting SMP configuration: [ 0.067041] .... node #0, CPUs: #1 #2 #3 [ 0.071083] smp: Brought up 1 node, 4 CPUs [ 0.073056] smpboot: Max logical packages: 1 [ 0.074009] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.138631] node 0 deferred pages initialised in 62ms [ 0.142105] devtmpfs: initialized [ 0.143340] x86/mm: Memory block size: 128MB [ 0.147000] gcov: version magic: 0x41383552 [ 0.154020] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.155083] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.156287] pinctrl core: initialized pinctrl subsystem [ 0.157190] [ 0.157756] ************************************************************* [ 0.158013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.159011] ** ** [ 0.160013] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.161018] ** ** [ 0.162019] ** This means that this kernel is built to expose internal ** [ 0.163015] ** IOMMU data structures, which may compromise security on ** [ 0.164019] ** your system. ** [ 0.165017] ** ** [ 0.166018] ** If you see this message and you are not debugging the ** [ 0.167017] ** kernel, report this immediately to your vendor! ** [ 0.168017] ** ** [ 0.169013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.170016] ************************************************************* [ 0.171948] NET: Registered protocol family 16 [ 0.174529] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.177056] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.179101] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.182202] cpuidle: using governor menu [ 0.183744] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.185472] PCI: Using configuration type 1 for base access [ 0.187109] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.194077] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.195011] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.197164] cryptd: max_cpu_qlen set to 1000 [ 0.199294] ACPI: Added _OSI(Module Device) [ 0.201009] ACPI: Added _OSI(Processor Device) [ 0.202007] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.203008] ACPI: Added _OSI(Processor Aggregator Device) [ 0.207649] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.213030] ACPI: Interpreter enabled [ 0.214055] ACPI: PM: (supports S0 S3 S4 S5) [ 0.215078] ACPI: Using IOAPIC for interrupt routing [ 0.216081] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.217937] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.229916] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.231033] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.234016] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.237155] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.243704] acpiphp: Slot [2] registered [ 0.245086] acpiphp: Slot [5] registered [ 0.246204] acpiphp: Slot [6] registered [ 0.248148] acpiphp: Slot [3] registered [ 0.250091] acpiphp: Slot [4] registered [ 0.251073] acpiphp: Slot [7] registered [ 0.252140] acpiphp: Slot [8] registered [ 0.253109] acpiphp: Slot [9] registered [ 0.254201] acpiphp: Slot [10] registered [ 0.256087] acpiphp: Slot [11] registered [ 0.258210] acpiphp: Slot [12] registered [ 0.260096] acpiphp: Slot [13] registered [ 0.262130] acpiphp: Slot [14] registered [ 0.264125] acpiphp: Slot [15] registered [ 0.266105] acpiphp: Slot [16] registered [ 0.268091] acpiphp: Slot [17] registered [ 0.269085] acpiphp: Slot [18] registered [ 0.271094] acpiphp: Slot [19] registered [ 0.272085] acpiphp: Slot [20] registered [ 0.274116] acpiphp: Slot [21] registered [ 0.276070] acpiphp: Slot [22] registered [ 0.278300] acpiphp: Slot [23] registered [ 0.280230] acpiphp: Slot [24] registered [ 0.282166] acpiphp: Slot [25] registered [ 0.283058] acpiphp: Slot [26] registered [ 0.285122] acpiphp: Slot [27] registered [ 0.286125] acpiphp: Slot [28] registered [ 0.287066] acpiphp: Slot [29] registered [ 0.289085] acpiphp: Slot [30] registered [ 0.290171] acpiphp: Slot [31] registered [ 0.292073] PCI host bridge to bus 0000:00 [ 0.293014] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.295020] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.298023] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.300018] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.302027] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.306093] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.309401] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.312444] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.316559] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.328039] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.332416] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.335015] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.337011] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.339010] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.341446] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.343980] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.345037] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.347931] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.352012] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.364015] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.368995] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.377491] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.386022] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.393030] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.410017] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.420266] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.425015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.431013] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.448070] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.460049] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.462212] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.463353] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.465336] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.467140] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.471172] iommu: Default domain type: Passthrough [ 0.472000] SCSI subsystem initialized [ 0.473123] ACPI: bus type USB registered [ 0.475270] usbcore: registered new interface driver usbfs [ 0.477037] usbcore: registered new interface driver hub [ 0.478055] usbcore: registered new device driver usb [ 0.479178] pps_core: LinuxPPS API ver. 1 registered [ 0.480005] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.482027] PTP clock support registered [ 0.483152] EDAC MC: Ver: 3.0.0 [ 0.484317] PCI: Using ACPI for IRQ routing [ 0.486722] NetLabel: Initializing [ 0.487007] NetLabel: domain hash size = 128 [ 0.488007] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.490089] NetLabel: unlabeled traffic allowed by default [ 0.491188] vgaarb: loaded [ 0.492184] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.493000] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.497063] clocksource: Switched to clocksource kvm-clock [ 0.593138] VFS: Disk quotas dquot_6.6.0 [ 0.594975] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.597951] *** VALIDATE ramfs *** [ 0.599530] *** VALIDATE hugetlbfs *** [ 0.602165] pnp: PnP ACPI init [ 0.605080] pnp: PnP ACPI: found 6 devices [ 0.620821] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.626953] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.629249] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.632205] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.635435] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.638324] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.641630] NET: Registered protocol family 2 [ 0.644618] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.651080] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.655082] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.660428] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.664202] TCP: Hash tables configured (established 65536 bind 65536) [ 0.666366] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.669288] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.672346] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.675607] NET: Registered protocol family 1 [ 0.679164] RPC: Registered named UNIX socket transport module. [ 0.681344] RPC: Registered udp transport module. [ 0.683122] RPC: Registered tcp transport module. [ 0.684951] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.687448] NET: Registered protocol family 44 [ 0.689037] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.691266] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.693637] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.696093] PCI: CLS 0 bytes, default 64 [ 0.697917] Unpacking initramfs... [ 2.308291] debug: unmapping init [mem 0xffff88b0fcc64000-0xffff88b0fffcffff] [ 2.311545] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.313154] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.315353] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.819362] Initialise system trusted keyrings [ 2.821030] Key type blacklist registered [ 2.822914] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.832549] zbud: loaded [ 2.835566] *** VALIDATE nfs *** [ 2.836710] *** VALIDATE nfs4 *** [ 2.838197] pstore: using deflate compression [ 2.841748] Platform Keyring initialized [ 2.943471] NET: Registered protocol family 38 [ 2.944984] Key type asymmetric registered [ 2.946349] Asymmetric key parser 'x509' registered [ 2.948171] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.951708] io scheduler mq-deadline registered [ 2.954063] io scheduler kyber registered [ 2.955907] io scheduler bfq registered [ 2.958389] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.960790] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.963026] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.965152] ACPI: Power Button [PWRF] [ 2.972272] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.979507] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.004127] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.033881] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.068748] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.130876] Non-volatile memory driver v1.3 [ 3.132111] Linux agpgart interface v0.103 [ 3.190241] virtio_blk virtio1: [vda] 146536 512-byte logical blocks (75.0 MB/71.6 MiB) [ 3.193325] vda: detected capacity change from 0 to 75026432 [ 3.219765] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.223062] vdb: detected capacity change from 0 to 1073741824 [ 3.242969] libphy: Fixed MDIO Bus: probed [ 3.250615] usbcore: registered new interface driver usbserial_generic [ 3.253605] usbserial: USB Serial support registered for generic [ 3.256499] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.262114] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.263941] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.266545] mousedev: PS/2 mouse device common for all mice [ 3.269870] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.272505] rtc_cmos 00:05: RTC can wake from S4 [ 3.279120] rtc_cmos 00:05: registered as rtc0 [ 3.283144] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.287565] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.288098] intel_pstate: CPU model not supported [ 3.290415] hid: raw HID events driver (C) Jiri Kosina [ 3.298780] usbcore: registered new interface driver usbhid [ 3.301370] usbhid: USB HID core driver [ 3.303346] drop_monitor: Initializing network drop monitor service [ 3.304149] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.309760] Initializing XFRM netlink socket [ 3.310185] NET: Registered protocol family 10 [ 3.311484] Segment Routing with IPv6 [ 3.311526] NET: Registered protocol family 17 [ 3.311809] mpls_gso: MPLS GSO support [ 3.328158] RAS: Correctable Errors collector initialized. [ 3.330160] AVX version of gcm_enc/dec engaged. [ 3.331840] AES CTR mode by8 optimization enabled [ 3.415762] sched_clock: Marking stable (3415744777, 0)->(4385453389, -969708612) [ 3.420989] registered taskstats version 1 [ 3.423468] Loading compiled-in X.509 certificates [ 3.425323] zswap: loaded using pool lzo/zbud [ 3.453376] Key type big_key registered [ 3.467431] Key type encrypted registered [ 3.469148] ima: No TPM chip found, activating TPM-bypass! [ 3.471353] ima: Allocated hash algorithm: sha1 [ 3.473238] ima: No architecture policies found [ 3.474950] evm: Initialising EVM extended attributes: [ 3.476791] evm: security.selinux [ 3.477889] evm: security.ima [ 3.479103] evm: security.capability [ 3.480538] evm: HMAC attrs: 0x1 [ 3.483727] rtc_cmos 00:05: setting system clock to 2026-08-22 04:27:49 UTC (1787372869) [ 3.491592] debug: unmapping init [mem 0xffffffffb9803000-0xffffffffb99fffff] [ 3.495098] debug: unmapping init [mem 0xffffffffb8582000-0xffffffffb8858fff] [ 3.504096] Write protecting the kernel read-only data: 28672k [ 3.507309] debug: unmapping init [mem 0xffffffffb6c03000-0xffffffffb6dfffff] [ 3.509904] debug: unmapping init [mem 0xffffffffb7514000-0xffffffffb75fffff] [ 3.545845] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.553297] systemd[1]: Detected virtualization kvm. [ 3.554937] systemd[1]: Detected architecture x86-64. [ 3.557083] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.585096] systemd[1]: No hostname configured. [ 3.586989] systemd[1]: Set hostname to . [ 3.588922] random: systemd: uninitialized urandom read (16 bytes read) [ 3.591620] systemd[1]: Initializing machine ID from random generator. [ 3.655623] random: ln: uninitialized urandom read (6 bytes read) [ 3.767852] random: systemd: uninitialized urandom read (16 bytes read) [ 3.771138] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 3.781892] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 3.792214] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Slices. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Swap. [ OK ] Listening on Journal Socket. [ OK ] Reached target Sockets. Starting Journal Service... Starting Setup Virtual Console... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Memstrack Anylazing Service. Starting Apply Kernel Variables... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Reached target Timers. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.719918] device-mapper: uevent: version 1.0.3 [ 4.723806] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.779719] virtio_net virtio0 ens2: renamed from eth0 [ 6.040122] scsi host0: ata_piix [ 6.068154] scsi host1: ata_piix [ 6.069349] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 6.071851] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 11.509442] random: crng init done [ 11.511446] random: 7 urandom warning(s) missed due to ratelimiting [ 11.582023] dracut-initqueue[580]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 13.641377] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Timers. [ 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. Stopping Hardware RNG Entropy Gatherer Daemon... [ 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 target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 15.740609] printk: systemd: 26 output lines suppressed due to ratelimiting [ 16.184941] SELinux: Disabled at runtime. [ 16.246095] 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) [ 16.256641] systemd[1]: Detected virtualization kvm. [ 16.260371] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 17.893531] systemd[1]: initrd-switch-root.service: Succeeded. [ 17.898587] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 17.910466] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 17.923872] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 17.940237] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 18.000579] systemd[1]: Starting Journal Service... Starting Journal Service... [ 18.042577] systemd[1]: Stopped target Switch Root. [ OK ] Stopped target Switch Root. Mounting POSIX Message Queue File System... [ OK ] Created slice User and Session Slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target rpc_pipefs.target. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Control Socket. [ 18.341031] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting Remount Root and Kernel File Systems... Starting Apply Kernel Variables... [ OK ] Stopped target Initrd Root File System. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Reached target Slices. [ OK ] Created slice system-getty.slice. [ OK ] Stopped target Initrd File Systems. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Kernel Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. Mounting Kernel Debug File System... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Reached target Local Encrypted Volumes. Mounting Huge Pages File System... [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Starting udev Coldplug all Devices... [ OK ] Started Journal Service. [ 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. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 20.282171] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 21.601813] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 21.825823] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 23.317781] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 23.367633] 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 (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 (12s / no limit) [ **] A start job is running for Configur…only root support (13s / no limit)[ 31.002673] Key type dns_resolver registered [ *] 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)[ 32.298227] hrtimer: interrupt took 3096495 ns [ ***] A start job is running for Configur…only root support (15s / no limit) [ *** ] A start job is running for Configur…only root support (15s / no limit)[ 33.955864] NFS: Registering the id_resolver key type [ 33.957794] Key type id_resolver registered [ 33.959979] Key type id_legacy registered [ *** ] A start job is running for Configur…only root support (16s / no limit) [*** ] A start job is running for Configur…only root support (16s / no limit) [** ] A start job is running for Configur…only root support (17s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Load/Save Random Seed... Starting Create Volatile Files and Directories... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Login Service... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started Login Service. [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting 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 oleg141-client login: [ 113.022263] libcfs: loading out-of-tree module taints kernel. [ 113.215120] Key type ._llcrypt registered [ 113.223475] Key type .llcrypt registered [ 113.650936] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 113.664557] alg: No test for adler32 (adler32-zlib) [ 115.182499] Lustre: Lustre: Build Version: 2.17.57_45_gb800aec [ 116.113443] LNet: Added LNI 192.168.201.41@tcp [8/256/0/180] [ 117.999784] Key type lgssc registered [ 119.850958] Lustre: Echo OBD driver; http://www.lustre.org/ [ 248.056171] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [ 253.402692] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 272.800294] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing check_logdir /tmp/testlogs/ [ 273.913725] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 23s idle [ 278.604886] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing yml_node [ 282.915777] Lustre: DEBUG MARKER: Client: 2.17.57.45 [ 286.395178] Lustre: DEBUG MARKER: MDS: 2.17.57.45 [ 290.223892] Lustre: DEBUG MARKER: OSS: 2.17.57.45 [ 292.246914] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Sat Aug 22 00:32:36 EDT 2026 [ 314.018812] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 316.124533] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 12a 9 [ 318.924733] Lustre: DEBUG MARKER: === sanity-quota: start setup 00:33:03 (1787373183) === [ 324.791614] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing check_config_client /mnt/lustre [ 341.984227] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 353.242311] Lustre: DEBUG MARKER: === sanity-quota: finish setup 00:33:37 (1787373217) === [ 422.899804] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 00:34:47 (1787373287) [ 468.449898] Lustre: lustre-OST0001-osc-ffff88b159d3b000: disconnect after 24s idle [ 468.459554] Lustre: Skipped 1 previous similar message [ 478.687287] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 24s idle [ 482.288465] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 00:35:46 (1787373346) [ 499.495515] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 507.634835] Lustre: DEBUG MARKER: Write... [ 510.511849] Lustre: DEBUG MARKER: Write out of block quota ... [ 524.767587] Lustre: lustre-OST0001-osc-ffff88b159d3b000: disconnect after 20s idle [ 545.260244] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 23s idle [ 558.621629] Lustre: DEBUG MARKER: -------------------------------------- [ 559.953915] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 568.073332] Lustre: DEBUG MARKER: Write... [ 570.760552] Lustre: DEBUG MARKER: Write out of block quota ... [ 586.207828] Lustre: lustre-OST0001-osc-ffff88b159d3b000: disconnect after 21s idle [ 606.705193] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 23s idle [ 615.739546] Lustre: DEBUG MARKER: -------------------------------------- [ 617.260492] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 619.883840] Lustre: DEBUG MARKER: Write... [ 622.146645] Lustre: DEBUG MARKER: Write out of block quota ... [ 657.888951] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 21s idle [ 657.891616] Lustre: Skipped 1 previous similar message [ 690.209401] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 00:39:14 (1787373554) [ 707.512367] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 726.762968] Lustre: DEBUG MARKER: Write... [ 729.625718] Lustre: DEBUG MARKER: Write out of block quota ... [ 744.940433] Lustre: lustre-OST0001-osc-ffff88b159d3b000: disconnect after 20s idle [ 744.947874] Lustre: Skipped 2 previous similar messages [ 776.851491] Lustre: DEBUG MARKER: -------------------------------------- [ 778.490322] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 785.498841] Lustre: DEBUG MARKER: Write... [ 787.809251] Lustre: DEBUG MARKER: Write out of block quota ... [ 839.166534] Lustre: DEBUG MARKER: -------------------------------------- [ 840.723720] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 843.757729] Lustre: DEBUG MARKER: Write... [ 846.674476] Lustre: DEBUG MARKER: Write out of block quota ... [ 883.169355] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 23s idle [ 883.178925] Lustre: Skipped 4 previous similar messages [ 920.354285] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 00:43:04 (1787373784) [ 936.929938] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 960.053641] Lustre: DEBUG MARKER: Write... [ 964.471920] Lustre: DEBUG MARKER: Write out of block quota ... [ 1057.567114] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 00:45:21 (1787373921) [ 1075.596083] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 1098.224299] Lustre: DEBUG MARKER: Write... [ 1100.929330] Lustre: DEBUG MARKER: Write out of block quota ... [ 1144.295458] Lustre: lustre-OST0001-osc-ffff88b159d3b000: disconnect after 24s idle [ 1144.305932] Lustre: Skipped 7 previous similar messages [ 1190.008984] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 00:47:34 (1787374054) [ 1207.857454] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 1222.533698] Lustre: DEBUG MARKER: Write... [ 1225.666732] Lustre: DEBUG MARKER: Write out of block quota ... [ 1238.982643] Lustre: DEBUG MARKER: Write... [ 1300.974237] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 00:49:25 (1787374165) [ 1316.585390] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1327.720859] Lustre: DEBUG MARKER: Write... [ 1329.870168] Lustre: DEBUG MARKER: Write out of block quota ... [ 1377.411683] Lustre: DEBUG MARKER: Write... [ 1379.483500] Lustre: DEBUG MARKER: Write out of block quota ... [ 1427.617554] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 00:51:32 (1787374292) [ 1441.722178] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 1452.670456] Lustre: DEBUG MARKER: Write... [ 1462.849080] Lustre: DEBUG MARKER: Write out of block quota ... [ 1543.193683] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 00:53:28 (1787374408) [ 1544.864224] Lustre: DEBUG MARKER: SKIP: sanity-quota test_1h need >= 2.13.57 and ldiskfs for fallocate [ 1546.740772] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 00:53:31 (1787374411) [ 1562.149799] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1573.909571] Lustre: DEBUG MARKER: Write... [ 1576.675101] Lustre: DEBUG MARKER: Write out of block quota ... [ 1615.424854] Lustre: DEBUG MARKER: Write... [ 1618.538738] Lustre: DEBUG MARKER: Write out of block quota ... [ 1671.655456] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 23s idle [ 1671.667408] Lustre: Skipped 14 previous similar messages [ 1673.307932] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 00:55:37 (1787374537) [ 1691.023259] Lustre: DEBUG MARKER: -------------------------------------- [ 1692.224243] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 2039.037592] Lustre: DEBUG MARKER: == sanity-quota test 1k: LQA: Block hard limit (normal use and out of quota) ========================================================== 01:01:43 (1787374903) [ 2061.433244] Lustre: DEBUG MARKER: Write... [ 2065.004958] Lustre: DEBUG MARKER: Write out of block quota ... [ 2108.792361] Lustre: DEBUG MARKER: Write... [ 2111.989247] Lustre: DEBUG MARKER: Write out of block quota ... [ 2151.647708] Lustre: DEBUG MARKER: Write... [ 2156.641569] Lustre: DEBUG MARKER: Write out of block quota ... [ 2202.905543] Lustre: DEBUG MARKER: == sanity-quota test 1l: Async writes should not be rejected by quota with root_prj_enable ========================================================== 01:04:27 (1787375067) [ 2203.581146] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [ 2262.433524] Lustre: Unmounted lustre-client [ 2263.703217] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 2265.241910] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 01:05:29 (1787375129) [ 2312.163876] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 20s idle [ 2312.170057] Lustre: Skipped 14 previous similar messages [ 2354.962213] Lustre: DEBUG MARKER: Write after timer goes off [ 2357.006906] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2498.460268] Lustre: DEBUG MARKER: Write after timer goes off [ 2501.323527] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2641.384863] Lustre: DEBUG MARKER: Write after timer goes off [ 2643.827856] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2749.320485] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 01:13:33 (1787375613) [ 2841.612412] Lustre: DEBUG MARKER: Write after timer goes off [ 2844.326908] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2939.871356] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 23s idle [ 2939.878408] Lustre: Skipped 18 previous similar messages [ 2980.271531] Lustre: DEBUG MARKER: Write after timer goes off [ 2982.903123] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3122.778930] Lustre: DEBUG MARKER: Write after timer goes off [ 3125.791653] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3250.193413] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 01:21:54 (1787376114) [ 3356.901893] Lustre: DEBUG MARKER: Write after timer goes off [ 3360.131256] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3472.266570] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 3474.144509] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 01:25:38 (1787376338) [ 3492.144028] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 3564.517043] Lustre: lustre-OST0001-osc-ffff88b159d3b000: disconnect after 22s idle [ 3564.519809] Lustre: Skipped 19 previous similar messages [ 3637.497024] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 01:28:21 (1787376501) [ 3793.815606] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 01:30:57 (1787376657) [ 3830.761473] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection to lustre-OST0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3845.827419] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 4013.294526] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 01:34:37 (1787376877) [ 4061.153981] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection to lustre-OST0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4066.465508] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 4152.461615] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 01:36:57 (1787377017) [ 4189.151948] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 24s idle [ 4189.167499] Lustre: Skipped 12 previous similar messages [ 4189.173250] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [ 4189.184720] Lustre: lustre-MDT0000-mdc-ffff88b159d3b000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4189.198676] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a0d0587 to 0xe51c49183a163628 [ 4189.220865] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 4200.415195] Lustre: 2356:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787377050/real 1787377050] req@ffff88b158f14700 x1874196418522624/t0(0) o400->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787377066 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4361.271282] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 01:40:25 (1787377225) [ 4452.855747] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 01:41:57 (1787377317) [ 4454.767847] Lustre: DEBUG MARKER: SKIP: sanity-quota test_7e needs >= 2 MDTs [ 4456.847788] Lustre: DEBUG MARKER: == sanity-quota test 7f: Quota reintegration automatically ========================================================== 01:42:01 (1787377321) [ 4687.977295] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 01:45:52 (1787377552) [ 4890.593542] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 21s idle [ 4890.613633] Lustre: Skipped 8 previous similar messages [ 4900.971520] Lustre: DEBUG MARKER: SKIP: sanity-quota test_9 skipping SLOW test 9 [ 4903.162883] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 01:49:27 (1787377767) [ 4964.647323] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 01:50:28 (1787377828) [ 5021.860602] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12a skipping SLOW test 12a [ 5024.212925] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 01:51:28 (1787377888) [ 5026.174647] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12b needs >= 2 MDTs [ 5027.961320] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 01:51:32 (1787377892) [ 5097.210506] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 01:52:41 (1787377961) [ 5131.276419] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection to lustre-OST0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5147.492985] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 5147.512296] Lustre: Skipped 1 previous similar message [ 5202.791449] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 01:54:26 (1787378066) [ 5235.201438] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 01:54:59 (1787378099) [ 5255.098356] Lustre: setting import lustre-OST0000_UUID INACTIVE by administrator request [ 5261.443891] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection to lustre-OST0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5261.492776] LustreError: lustre-OST0000-osc-ffff88b159d3b000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 5261.505471] Lustre: lustre-OST0000-osc-ffff88b159d3b000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 5290.901575] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 01:55:54 (1787378154) [ 5292.830959] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 5294.393138] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 01:55:59 (1787378159) [ 5499.876925] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 22s idle [ 5499.884878] Lustre: Skipped 14 previous similar messages [ 5644.168714] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 02:01:49 (1787378509) [ 5660.779609] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5668.076570] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 5673.273695] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5675.544478] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5695.391508] Lustre: 2355:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787378545/real 1787378545] req@ffff88b158030000 x1874196422561792/t0(0) o400->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787378561 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5695.431213] Lustre: lustre-MDT0000-mdc-ffff88b159d3b000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5695.442314] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [ 5701.599469] Lustre: 2354:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787378550/real 1787378550] req@ffff88b150606a00 x1874196422563840/t0(0) o400->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787378566 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5701.642512] Lustre: 2354:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5705.714485] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a163628 to 0xe51c49183a1a06a8 [ 5705.730261] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 5705.767813] LustreError: 2353:0:(client.c:3448:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff88b1506c7100 x1874196422552576/t8589941265(8589941265) o101->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 592/608 e 0 to 0 dl 1787378587 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 5705.825373] Lustre: 2355:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787378555/real 1787378555] req@ffff88b150604700 x1874196422564352/t0(0) o400->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787378571 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5710.815274] Lustre: 2357:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787378560/real 1787378560] req@ffff88b1506c5f80 x1874196422564992/t0(0) o400->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787378576 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5714.447330] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5716.614458] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5726.898319] Lustre: DEBUG MARKER: (dd_pid=115100, time=3, timeout=600) [ 5775.572799] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5783.321536] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 5787.781407] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5789.505933] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5809.119135] Lustre: 2355:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787378658/real 1787378658] req@ffff88b158030e00 x1874196422600960/t0(0) o400->MGC192.168.201.141@tcp@192.168.201.141@tcp:26/25 lens 224/224 e 0 to 1 dl 1787378674 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5809.150623] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [ 5809.160982] Lustre: lustre-MDT0000-mdc-ffff88b159d3b000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5818.271204] Lustre: 2356:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787378668/real 1787378668] req@ffff88b1506c5f80 x1874196422602752/t0(0) o400->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787378684 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5818.300959] Lustre: 2356:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 5819.365740] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a1a06a8 to 0xe51c49183a1a0e3b [ 5819.376275] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 5819.382795] Lustre: Skipped 1 previous similar message [ 5834.799156] LustreError: 2353:0:(client.c:3448:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff88b158030000 x1874196422592128/t12884901904(12884901904) o101->lustre-MDT0000-mdc-ffff88b159d3b000@192.168.201.141@tcp:12/10 lens 592/608 e 0 to 0 dl 1787378716 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 5834.898084] Lustre: lustre-MDT0000-mdc-ffff88b159d3b000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [ 5840.621683] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5842.275630] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5847.621598] Lustre: DEBUG MARKER: (dd_pid=117509, time=0, timeout=600) [ 5909.345290] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 02:06:14 (1787378774) [ 5930.812785] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 5933.300418] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:2). [ 5940.431697] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 5942.205876] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:2). [ 5979.845676] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 02:07:24 (1787378844) [ 6004.877196] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 6021.421313] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 6023.163500] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 6024.880163] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 6027.210418] Lustre: DEBUG MARKER: Set quota for 1 times [ 6031.189220] Lustre: DEBUG MARKER: Set quota for 2 times [ 6035.172596] Lustre: DEBUG MARKER: Set quota for 3 times [ 6039.681540] Lustre: DEBUG MARKER: Set quota for 4 times [ 6043.713333] Lustre: DEBUG MARKER: Set quota for 5 times [ 6048.390904] Lustre: DEBUG MARKER: Set quota for 6 times [ 6052.618280] Lustre: DEBUG MARKER: Set quota for 7 times [ 6056.211186] Lustre: DEBUG MARKER: Set quota for 8 times [ 6106.080753] Lustre: lustre-OST0000-osc-ffff88b159d3b000: disconnect after 24s idle [ 6106.097194] Lustre: Skipped 13 previous similar messages [ 6107.805230] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 02:09:32 (1787378972) [ 6118.112848] Lustre: Unmounted lustre-client [ 6190.608399] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [ 6195.434239] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6215.576806] Lustre: Unmounted lustre-client [ 6293.050688] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [ 6299.024127] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6316.799488] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 02:13:00 (1787379180) [ 6319.095960] Lustre: DEBUG MARKER: SKIP: sanity-quota test_23 Overwrite in place is not guaranteed to be space neutral on ZFS [ 6321.433878] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 02:13:05 (1787379185) [ 6381.135155] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 02:14:05 (1787379245) [ 6433.402322] Lustre: DEBUG MARKER: Write... [ 6436.309989] Lustre: DEBUG MARKER: Write out of block quota ... [ 6499.874762] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 02:16:04 (1787379364) [ 6506.699920] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 02:16:11 (1787379371) [ 6518.464976] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 02:16:22 (1787379382) [ 6530.526350] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 02:16:34 (1787379394) [ 6540.310733] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 02:16:44 (1787379404) [ 6606.490381] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 6717.927979] Lustre: lustre-OST0000-osc-ffff88b160bf4000: disconnect after 24s idle [ 6717.944669] Lustre: Skipped 13 previous similar messages [ 6773.062368] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 6978.730665] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 02:24:02 (1787379842) [ 7049.638109] Lustre: DEBUG MARKER: Restart... [ 7051.816389] Lustre: Unmounted lustre-client [ 7147.651828] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [ 7153.198984] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7233.352681] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 02:28:17 (1787380097) [ 7312.577946] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 02:29:36 (1787380176) [ 8866.271271] Lustre: lustre-OST0000-osc-ffff88b151ab1000: disconnect after 20s idle [ 8866.273865] Lustre: Skipped 14 previous similar messages [ 9147.893911] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 03:00:12 (1787382012) [ 9159.653398] Lustre: Unmounted lustre-client [ 9242.644630] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [ 9247.873916] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 9268.207493] Lustre: lustre-OST0001-osc-ffff88b143d79800: disconnect after 23s idle [ 9268.217518] Lustre: Skipped 1 previous similar message [ 9287.037152] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 03:02:32 (1787382152) [ 9332.740403] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 03:03:17 (1787382197) [ 9377.667816] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 03:04:02 (1787382242) [ 9379.398685] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40c needs >= 2 MDTs [ 9381.305325] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 03:04:05 (1787382245) [ 9383.129098] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40d needs >= 2 MDTs [ 9384.990369] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 03:04:09 (1787382249) [ 9467.871364] Lustre: lustre-OST0000-osc-ffff88b143d79800: disconnect after 22s idle [ 9467.892068] Lustre: Skipped 5 previous similar messages [ 9476.120386] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 03:05:40 (1787382340) [ 9525.695836] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 03:06:30 (1787382390) [ 9611.533321] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 03:07:56 (1787382476) [ 9908.192203] Lustre: lustre-OST0000-osc-ffff88b143d79800: disconnect after 22s idle [ 9908.213469] Lustre: Skipped 5 previous similar messages [10324.243974] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [10334.557594] Lustre: Unmounted lustre-client [10473.542454] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [10478.383308] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10520.065274] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 03:23:04 (1787383384) [10526.385345] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 03:23:11 (1787383391) [10565.599319] Lustre: lustre-OST0000-osc-ffff88b1435e9000: disconnect after 21s idle [10565.604231] Lustre: Skipped 5 previous similar messages [10576.086066] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 03:24:00 (1787383440) [10639.926501] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 03:25:04 (1787383504) [10674.671722] Lustre: DEBUG MARKER: rename directory return 255 [10724.251643] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 03:26:28 (1787383588) [10758.220244] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 03:27:02 (1787383622) [10804.051780] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 03:27:48 (1787383668) [10941.526078] LustreError: 218513:0:(llite_lib.c:2160:ll_md_setattr()) md_setattr fails: rc = -122 [10985.661688] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 03:30:50 (1787383850) [11026.695642] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 03:31:30 (1787383890) [11077.219985] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 03:32:21 (1787383941) [11149.595589] LustreError: 224188:0:(file.c:251:ll_close_inode_openhandle()) lustre-clilmv-ffff88b1435e9000: inode [0x200000401:0xad:0x0] mdc close failed: rc = -22 [11169.759270] Lustre: lustre-OST0001-osc-ffff88b1435e9000: disconnect after 21s idle [11169.770629] Lustre: Skipped 9 previous similar messages [11225.059850] LustreError: 225564:0:(file.c:251:ll_close_inode_openhandle()) lustre-clilmv-ffff88b1435e9000: inode [0x200000401:0xad:0x0] mdc close failed: rc = -22 [11225.069371] LustreError: 225564:0:(file.c:251:ll_close_inode_openhandle()) Skipped 1 previous similar message [11256.750211] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 03:35:21 (1787384121) [11258.577478] Lustre: DEBUG MARKER: SKIP: sanity-quota test_59 ldiskfs only test [11260.140650] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 03:35:24 (1787384124) [11322.586763] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [11324.747878] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 03:36:29 (1787384189) [11360.685941] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [11362.720754] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 03:37:07 (1787384227) [11419.257561] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [11420.876501] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 03:38:05 (1787384285) [11471.562157] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 03:38:55 (1787384335) [11473.499665] Lustre: DEBUG MARKER: SKIP: sanity-quota test_67 ZFS grants some block space together with inode [11475.402066] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 03:38:59 (1787384339) [11553.391468] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 03:40:17 (1787384417) [11580.571779] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [11582.911525] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [11773.919300] Lustre: lustre-OST0000-osc-ffff88b1435e9000: disconnect after 24s idle [11773.926875] Lustre: Skipped 8 previous similar messages [11774.393301] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 03:43:58 (1787384638) [11828.089953] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 03:44:52 (1787384692) [11865.023540] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 03:45:29 (1787384729) [11866.955407] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71a ZFS grants some block space together with inode [11869.075712] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 03:45:33 (1787384733) [11870.937456] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71b ZFS grants some block space together with inode [11873.192368] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 03:45:37 (1787384737) [11893.017345] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [11912.708948] Lustre: DEBUG MARKER: Write... [11915.604382] Lustre: DEBUG MARKER: Write out of block quota ... [11979.271694] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 03:47:23 (1787384843) [12009.877280] Lustre: DEBUG MARKER: set to use default quota [12011.768924] Lustre: DEBUG MARKER: set default quota [12013.791757] Lustre: DEBUG MARKER: get default quota [12020.701950] Lustre: DEBUG MARKER: Test not out of quota [12025.324830] Lustre: DEBUG MARKER: Test out of quota [12038.102425] Lustre: DEBUG MARKER: Increase default quota [12068.118416] Lustre: DEBUG MARKER: Set quota to override default quota [12082.321306] Lustre: DEBUG MARKER: Set to use default quota again [12105.000447] Lustre: DEBUG MARKER: Cleanup [12177.597357] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 03:50:42 (1787385042) [12204.304405] Lustre: DEBUG MARKER: set default quota for qpool1 [12206.283900] Lustre: DEBUG MARKER: Write from user that hasn't lqe [12259.551659] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 03:52:03 (1787385123) [12345.962820] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 03:53:30 (1787385210) [12388.338713] Lustre: lustre-OST0000-osc-ffff88b1435e9000: disconnect after 20s idle [12388.350903] Lustre: Skipped 10 previous similar messages [12420.070494] Lustre: DEBUG MARKER: Write... [12423.858942] Lustre: DEBUG MARKER: Write out of block quota ... [12552.438172] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 03:56:56 (1787385416) [12597.431933] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 03:57:41 (1787385461) [12598.136205] Lustre: Mounted lustre-client read-only - version 2.17.57_45_gb800aec [12598.475314] Lustre: Unmounted lustre-client [12604.802736] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 03:57:49 (1787385469) [12606.235979] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78A need >= 2.13.57 and ldiskfs for fallocate [12607.929412] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 03:57:52 (1787385472) [12609.516287] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78a need >= 2.13.57 and ldiskfs for fallocate [12611.423533] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 03:57:56 (1787385476) [12632.972259] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 03:58:17 (1787385497) [12634.903608] Lustre: DEBUG MARKER: SKIP: sanity-quota test_80 ZFS grants some block space together with inode [12636.710349] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 03:58:21 (1787385501) [12654.000408] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [12664.808475] Lustre: lustre-MDT0000-mdc-ffff88b1435e9000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [12685.292191] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [12685.320108] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a3b0d27 to 0xe51c49183a3c364c [12685.353566] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [12695.674634] LustreError: lustre-MDT0000-mdc-ffff88b1435e9000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [12695.706047] Lustre: lustre-MDT0000-mdc-ffff88b1435e9000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [12727.206726] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 03:59:51 (1787385591) [12763.333353] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 04:00:27 (1787385627) [12799.631393] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 04:01:04 (1787385664) [12979.218369] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 04:04:03 (1787385843) [13033.444958] Lustre: lustre-OST0000-osc-ffff88b1435e9000: disconnect after 23s idle [13033.448075] Lustre: Skipped 16 previous similar messages [13067.104542] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 04:05:31 (1787385931) [13646.962937] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 04:15:10 (1787386510) [13719.519666] Lustre: lustre-OST0000-osc-ffff88b1435e9000: disconnect after 20s idle [13719.528934] Lustre: Skipped 1 previous similar message [13760.487426] Lustre: lustre-MDT0000-mdc-ffff88b1435e9000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [13775.846576] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [13775.860758] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a3c364c to 0xe51c49183a4c624e [13775.869610] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [13780.132506] LustreError: lustre-MDT0000-mdc-ffff88b1435e9000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13780.168813] Lustre: lustre-MDT0000-mdc-ffff88b1435e9000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [13807.344614] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 04:17:52 (1787386672) [13809.445769] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [13811.792687] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 04:17:56 (1787386676) [13823.923486] LustreError: 273812:0:(mdc_request.c:2191:mdc_quotactl()) lustre-MDT0000-mdc-ffff88b1435e9000: ptlrpc_queue_wait failed: rc = -1 [13840.932593] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 04:18:24 (1787386704) [13865.381072] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 04:18:49 (1787386729) [13881.172520] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [13892.537138] Lustre: Unmounted lustre-client [13894.615962] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 04:19:18 (1787386758) [13897.393157] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [13897.397678] Lustre: Skipped 2 previous similar messages [13907.763482] Lustre: Unmounted lustre-client [14016.032309] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [14042.239866] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [14073.662913] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [14074.400384] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [14089.699350] Lustre: lustre-MDT0000-mdc-ffff88b16022a800: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [14105.064577] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [14105.090163] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a4c66ca to 0xe51c49183a4c68c9 [14105.102204] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [14109.306666] LustreError: lustre-MDT0000-mdc-ffff88b16022a800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14109.333699] Lustre: lustre-MDT0000-mdc-ffff88b16022a800: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [14118.787323] Lustre: DEBUG MARKER: oleg141-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [14120.821831] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [14131.750111] Lustre: Unmounted lustre-client [14299.567590] Lustre: Mounted lustre-client - version 2.17.57_45_gb800aec [14306.663924] Lustre: DEBUG MARKER: Using TIMEOUT=20 [14321.193321] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 04:26:25 (1787387185) [14325.215361] Lustre: lustre-OST0000-osc-ffff88b1491b8000: disconnect after 23s idle [14325.218044] Lustre: Skipped 7 previous similar messages [14337.831634] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 04:26:42 (1787387202) [14432.187259] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 04:28:16 (1787387296) [14478.849272] Lustre: lustre-MDT0000-mdc-ffff88b1491b8000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [14494.194335] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [14494.237933] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a4c6db5 to 0xe51c49183a4c725b [14494.251646] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [14509.690260] LustreError: lustre-MDT0000-mdc-ffff88b1491b8000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14509.708450] Lustre: lustre-MDT0000-mdc-ffff88b1491b8000: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [14514.664631] Lustre: lustre-MDT0000-mdc-ffff88b1491b8000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [14535.149607] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [14535.180845] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a4c725b to 0xe51c49183a4c7708 [14535.198275] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [14544.544946] LustreError: lustre-MDT0000-mdc-ffff88b1491b8000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14551.916420] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 04:30:15 (1787387415) [14587.752080] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 04:30:51 (1787387451) [14639.041685] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 04:31:43 (1787387503) [14641.185553] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 the test in only needed to run on LDiskFS [14643.469817] Lustre: DEBUG MARKER: == sanity-quota test 97a: LQA control commands =========== 04:31:47 (1787387507) [14676.427525] Lustre: DEBUG MARKER: == sanity-quota test 97b: Check LQA internals ============ 04:32:20 (1787387540) [14720.022279] Lustre: DEBUG MARKER: adding 50 LQA ranges took 2s [14727.085974] Lustre: DEBUG MARKER: Removing 50 LQA ranges took 1s [14738.475376] Lustre: DEBUG MARKER: == sanity-quota test 97c: LQA lfs quota commands and MDS restart consistency ========================================================== 04:33:22 (1787387602) [14759.404074] Lustre: lustre-MDT0000-mdc-ffff88b1491b8000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [14759.436147] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [14759.469226] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a4c7708 to 0xe51c49183a4c7c87 [14759.490878] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [14759.504846] Lustre: Skipped 1 previous similar message [14760.479269] Lustre: 2357:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787387610/real 1787387610] req@ffff88b1519d1180 x1874196462405760/t0(0) o400->lustre-MDT0000-mdc-ffff88b1491b8000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787387626 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14760.512729] Lustre: 2357:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 1 previous similar message [14765.543809] Lustre: 2355:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787387615/real 1787387615] req@ffff88b1442cdc00 x1874196462406016/t0(0) o400->lustre-MDT0000-mdc-ffff88b1491b8000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787387631 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14770.656355] Lustre: 2356:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787387620/real 1787387620] req@ffff88b1519d3800 x1874196462406272/t0(0) o400->lustre-MDT0000-mdc-ffff88b1491b8000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787387636 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14780.277477] Lustre: DEBUG MARKER: == sanity-quota test 97d: LQA disk persistence using standard commands ========================================================== 04:34:04 (1787387644) [14825.959838] LustreError: MGC192.168.201.141@tcp: Connection to MGS (at 192.168.201.141@tcp) was lost; in progress operations using this service will fail [14825.977788] Lustre: lustre-MDT0000-mdc-ffff88b1491b8000: Connection to lustre-MDT0000 (at 192.168.201.141@tcp) was lost; in progress operations using this service will wait for recovery to complete [14826.005294] Lustre: Evicted from MGS (at 192.168.201.141@tcp) after server handle changed from 0xe51c49183a4c7c87 to 0xe51c49183a4c7f89 [14826.020241] Lustre: MGC192.168.201.141@tcp: Connection restored to 192.168.201.141@tcp (at 192.168.201.141@tcp) [14826.030058] Lustre: Skipped 1 previous similar message [14826.783248] Lustre: 2357:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787387676/real 1787387676] req@ffff88b1618b1c00 x1874196462412416/t0(0) o400->lustre-MDT0000-mdc-ffff88b1491b8000@192.168.201.141@tcp:12/10 lens 224/224 e 0 to 1 dl 1787387692 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14876.559696] Lustre: DEBUG MARKER: == sanity-quota test 97e: LQA add/remove should reject invalid ranges ========================================================== 04:35:40 (1787387740) [14892.538487] Lustre: DEBUG MARKER: == sanity-quota test 98: Verify MDT retry on -EDQUOT during mkdir ========================================================== 04:35:57 (1787387757) [14894.756412] Lustre: DEBUG MARKER: SKIP: sanity-quota test_98 needs >= 2 MDTs [14897.278261] Lustre: DEBUG MARKER: == sanity-quota test 300: inode quota with MDT directory migration at 80% limit ========================================================== 04:36:01 (1787387761) [14899.391331] Lustre: DEBUG MARKER: SKIP: sanity-quota test_300 needs >= 2 MDTs [14905.930806] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 14611 sec ======== 04:36:09 (1787387769) [14908.192757] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 04:36:12 (1787387772) === [14912.238514] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 04:36:16 (1787387776) === [14915.230020] Lustre: Unmounted lustre-client [14946.070497] Key type lgssc unregistered [14946.426582] LNet: 298774:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [14946.439825] LNetError: 298774:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [14946.468324] LNet: Removed LNI 192.168.201.41@tcp [14947.293210] Key type .llcrypt unregistered [14947.296545] Key type ._llcrypt unregistered