[ 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 457970883 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2400.000 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 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: 2829700K/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.001017] APIC: Switch to symmetric I/O mode setup [ 0.003123] x2apic enabled [ 0.004009] Switched APIC routing to physical x2apic. [ 0.006011] kvm-guest: setup PV IPIs [ 0.009815] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.010000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 0.011016] Calibrating delay loop (skipped) preset value.. 4800.00 BogoMIPS (lpj=2400000) [ 0.012014] pid_max: default: 32768 minimum: 301 [ 0.014107] LSM: Security Framework initializing [ 0.015069] Yama: becoming mindful. [ 0.016055] SELinux: Initializing. [ 0.017085] *** VALIDATE selinux *** [ 0.025778] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.029800] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.030143] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031107] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.032113] *** VALIDATE tmpfs *** [ 0.034368] *** VALIDATE proc *** [ 0.036055] *** VALIDATE cgroup *** [ 0.037014] *** VALIDATE cgroup2 *** [ 0.038300] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.039161] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.040012] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.041027] Spectre V2 : User space: Vulnerable [ 0.042010] Speculative Store Bypass: Vulnerable [ 0.045143] debug: unmapping init [mem 0xffffffff89859000-0xffffffff89860fff] [ 0.047173] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.048672] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.049026] ... version: 2 [ 0.050015] ... bit width: 48 [ 0.051014] ... generic registers: 4 [ 0.052012] ... value mask: 0000ffffffffffff [ 0.053016] ... max period: 00007fffffffffff [ 0.054015] ... fixed-purpose events: 3 [ 0.055012] ... event mask: 000000070000000f [ 0.056315] rcu: Hierarchical SRCU implementation. [ 0.058530] smp: Bringing up secondary CPUs ... [ 0.059787] x86: Booting SMP configuration: [ 0.060032] .... node #0, CPUs: #1 #2 #3 [ 0.064051] smp: Brought up 1 node, 4 CPUs [ 0.066019] smpboot: Max logical packages: 1 [ 0.067018] smpboot: Total of 4 processors activated (19200.00 BogoMIPS) [ 0.269280] node 0 deferred pages initialised in 200ms [ 0.273270] devtmpfs: initialized [ 0.275348] x86/mm: Memory block size: 128MB [ 0.278965] gcov: version magic: 0x41383552 [ 0.282342] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.283094] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.285175] pinctrl core: initialized pinctrl subsystem [ 0.287302] [ 0.287794] ************************************************************* [ 0.290015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.292018] ** ** [ 0.295020] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.297017] ** ** [ 0.300024] ** This means that this kernel is built to expose internal ** [ 0.303020] ** IOMMU data structures, which may compromise security on ** [ 0.305017] ** your system. ** [ 0.307018] ** ** [ 0.310019] ** If you see this message and you are not debugging the ** [ 0.312016] ** kernel, report this immediately to your vendor! ** [ 0.315032] ** ** [ 0.317015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.319017] ************************************************************* [ 0.322488] NET: Registered protocol family 16 [ 0.324531] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.327108] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.330110] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.334538] cpuidle: using governor menu [ 0.336593] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.339739] PCI: Using configuration type 1 for base access [ 0.341142] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.350134] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.353041] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.356168] cryptd: max_cpu_qlen set to 1000 [ 0.360294] ACPI: Added _OSI(Module Device) [ 0.361027] ACPI: Added _OSI(Processor Device) [ 0.363020] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.365022] ACPI: Added _OSI(Processor Aggregator Device) [ 0.370000] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.377405] ACPI: Interpreter enabled [ 0.378081] ACPI: PM: (supports S0 S3 S4 S5) [ 0.380016] ACPI: Using IOAPIC for interrupt routing [ 0.382172] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.385861] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.397992] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.400042] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.403023] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.407084] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.412312] acpiphp: Slot [2] registered [ 0.414126] acpiphp: Slot [5] registered [ 0.416145] acpiphp: Slot [6] registered [ 0.418138] acpiphp: Slot [3] registered [ 0.419150] acpiphp: Slot [4] registered [ 0.421147] acpiphp: Slot [7] registered [ 0.423163] acpiphp: Slot [8] registered [ 0.425154] acpiphp: Slot [9] registered [ 0.426164] acpiphp: Slot [10] registered [ 0.428170] acpiphp: Slot [11] registered [ 0.429096] acpiphp: Slot [12] registered [ 0.430138] acpiphp: Slot [13] registered [ 0.432138] acpiphp: Slot [14] registered [ 0.433177] acpiphp: Slot [15] registered [ 0.435140] acpiphp: Slot [16] registered [ 0.436135] acpiphp: Slot [17] registered [ 0.438165] acpiphp: Slot [18] registered [ 0.440162] acpiphp: Slot [19] registered [ 0.442223] acpiphp: Slot [20] registered [ 0.444143] acpiphp: Slot [21] registered [ 0.445195] acpiphp: Slot [22] registered [ 0.446152] acpiphp: Slot [23] registered [ 0.448668] acpiphp: Slot [24] registered [ 0.450207] acpiphp: Slot [25] registered [ 0.452167] acpiphp: Slot [26] registered [ 0.454117] acpiphp: Slot [27] registered [ 0.457142] acpiphp: Slot [28] registered [ 0.460125] acpiphp: Slot [29] registered [ 0.461116] acpiphp: Slot [30] registered [ 0.463115] acpiphp: Slot [31] registered [ 0.465070] PCI host bridge to bus 0000:00 [ 0.466014] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.468027] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.471021] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.473021] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.476029] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.478024] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.480226] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.482996] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.487299] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.494524] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.498980] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.503030] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.505024] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.508025] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.512691] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.515823] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.519074] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.524913] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.528776] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.540016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.544022] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.549140] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.561017] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.570016] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.592946] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.603333] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.615017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.621014] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.633019] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.643464] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.647440] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.650461] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.652545] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.655323] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.660301] iommu: Default domain type: Passthrough [ 0.662545] SCSI subsystem initialized [ 0.664292] ACPI: bus type USB registered [ 0.666179] usbcore: registered new interface driver usbfs [ 0.669215] usbcore: registered new interface driver hub [ 0.672127] usbcore: registered new device driver usb [ 0.674245] pps_core: LinuxPPS API ver. 1 registered [ 0.676022] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.680090] PTP clock support registered [ 0.682153] EDAC MC: Ver: 3.0.0 [ 0.684178] PCI: Using ACPI for IRQ routing [ 0.687208] NetLabel: Initializing [ 0.688008] NetLabel: domain hash size = 128 [ 0.689008] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.690081] NetLabel: unlabeled traffic allowed by default [ 0.692117] vgaarb: loaded [ 0.693233] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.695012] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.699324] clocksource: Switched to clocksource kvm-clock [ 0.805093] VFS: Disk quotas dquot_6.6.0 [ 0.807071] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.809904] *** VALIDATE ramfs *** [ 0.811446] *** VALIDATE hugetlbfs *** [ 0.813271] pnp: PnP ACPI init [ 0.815892] pnp: PnP ACPI: found 6 devices [ 0.836144] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.839548] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.841693] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.843886] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.846591] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.849321] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.851429] NET: Registered protocol family 2 [ 0.853910] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.860495] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.864751] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.870848] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.874938] TCP: Hash tables configured (established 65536 bind 65536) [ 0.878758] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.882365] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.885490] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.888279] NET: Registered protocol family 1 [ 0.890771] RPC: Registered named UNIX socket transport module. [ 0.893017] RPC: Registered udp transport module. [ 0.894536] RPC: Registered tcp transport module. [ 0.896275] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.898879] NET: Registered protocol family 44 [ 0.900608] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.903106] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.905432] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.907815] PCI: CLS 0 bytes, default 64 [ 0.909512] Unpacking initramfs... [ 2.349928] debug: unmapping init [mem 0xffff9c7c3cc64000-0xffff9c7c3ffcffff] [ 2.354390] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.357172] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.360573] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 2.859236] Initialise system trusted keyrings [ 2.860921] Key type blacklist registered [ 2.862666] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.871771] zbud: loaded [ 2.874911] *** VALIDATE nfs *** [ 2.876165] *** VALIDATE nfs4 *** [ 2.877970] pstore: using deflate compression [ 2.880836] Platform Keyring initialized [ 2.982929] NET: Registered protocol family 38 [ 2.984388] Key type asymmetric registered [ 2.985638] Asymmetric key parser 'x509' registered [ 2.987588] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.990032] io scheduler mq-deadline registered [ 2.991920] io scheduler kyber registered [ 2.993532] io scheduler bfq registered [ 2.996116] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.000128] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.002448] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.005188] ACPI: Power Button [PWRF] [ 3.009624] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.016864] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.028775] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.057538] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.087720] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.092782] Non-volatile memory driver v1.3 [ 3.094688] Linux agpgart interface v0.103 [ 3.127479] virtio_blk virtio1: [vda] 150640 512-byte logical blocks (77.1 MB/73.6 MiB) [ 3.129571] vda: detected capacity change from 0 to 77127680 [ 3.143557] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.146475] vdb: detected capacity change from 0 to 1073741824 [ 3.151945] libphy: Fixed MDIO Bus: probed [ 3.156612] usbcore: registered new interface driver usbserial_generic [ 3.158285] usbserial: USB Serial support registered for generic [ 3.159962] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.163279] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.164726] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.166778] mousedev: PS/2 mouse device common for all mice [ 3.170276] rtc_cmos 00:05: RTC can wake from S4 [ 3.172711] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.178261] rtc_cmos 00:05: registered as rtc0 [ 3.179595] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.180863] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.186427] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.187882] intel_pstate: CPU model not supported [ 3.193786] hid: raw HID events driver (C) Jiri Kosina [ 3.196134] usbcore: registered new interface driver usbhid [ 3.198353] usbhid: USB HID core driver [ 3.200258] drop_monitor: Initializing network drop monitor service [ 3.203086] Initializing XFRM netlink socket [ 3.205219] NET: Registered protocol family 10 [ 3.208496] Segment Routing with IPv6 [ 3.210235] NET: Registered protocol family 17 [ 3.212620] mpls_gso: MPLS GSO support [ 3.219407] RAS: Correctable Errors collector initialized. [ 3.222371] AVX version of gcm_enc/dec engaged. [ 3.224238] AES CTR mode by8 optimization enabled [ 3.300873] sched_clock: Marking stable (3300840022, 0)->(4305435519, -1004595497) [ 3.304111] registered taskstats version 1 [ 3.306197] Loading compiled-in X.509 certificates [ 3.308600] zswap: loaded using pool lzo/zbud [ 3.333448] Key type big_key registered [ 3.346563] Key type encrypted registered [ 3.348558] ima: No TPM chip found, activating TPM-bypass! [ 3.350662] ima: Allocated hash algorithm: sha1 [ 3.352367] ima: No architecture policies found [ 3.354303] evm: Initialising EVM extended attributes: [ 3.355730] evm: security.selinux [ 3.356911] evm: security.ima [ 3.357988] evm: security.capability [ 3.359301] evm: HMAC attrs: 0x1 [ 3.361449] rtc_cmos 00:05: setting system clock to 2026-09-30 03:43:49 UTC (1790739829) [ 3.367949] debug: unmapping init [mem 0xffffffff8a803000-0xffffffff8a9fffff] [ 3.370902] debug: unmapping init [mem 0xffffffff89582000-0xffffffff89858fff] [ 3.375130] Write protecting the kernel read-only data: 28672k [ 3.378523] debug: unmapping init [mem 0xffffffff87c03000-0xffffffff87dfffff] [ 3.381432] debug: unmapping init [mem 0xffffffff88514000-0xffffffff885fffff] [ 3.411129] 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.419491] systemd[1]: Detected virtualization kvm. [ 3.421595] systemd[1]: Detected architecture x86-64. [ 3.423702] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.448245] systemd[1]: No hostname configured. [ 3.450202] systemd[1]: Set hostname to . [ 3.452639] random: systemd: uninitialized urandom read (16 bytes read) [ 3.455161] systemd[1]: Initializing machine ID from random generator. [ 3.589533] random: systemd: uninitialized urandom read (16 bytes read) [ 3.592652] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 3.597621] random: systemd: uninitialized urandom read (16 bytes read) [ 3.599986] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 3.604590] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Slices. [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... Starting Journal Service... [ OK ] Reached target Local Encrypted Volumes. Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Initrd Root Device. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.214222] device-mapper: uevent: version 1.0.3 [ 4.216814] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook.[ 4.457250] random: fast init done Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ 4.958979] virtio_net virtio0 ens2: renamed from eth0 [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.069718] scsi host0: ata_piix [ 5.082303] scsi host1: ata_piix [ 5.084606] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 5.087518] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 9.444238] dracut-initqueue[588]: RTNETLINK answers: File exists [ 9.864546] random: crng init done [ 9.865787] random: 7 urandom warning(s) missed due to ratelimiting 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... [ 10.332963] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ 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 target Sockets. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ 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... [ 11.503865] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.750411] SELinux: Disabled at runtime. [ 11.810191] 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) [ 11.818635] systemd[1]: Detected virtualization kvm. [ 11.820808] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.312908] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.317259] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.321511] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.325598] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.328820] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.337065] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.344792] systemd[1]: Mounting Huge Pages File System... Mounting Huge Pages File System... [ 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 ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice User and Session Slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. [ OK ] Listening on Process Core Dump Socket. [ OK ] Reached target Slices. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-getty.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. Activating swap /dev/disk/by-label/SWAP... Mounting POSIX Message Queue File System... Starting Create list of required st…ce nodes for the current kernel... [ 12.457140] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting Apply Kernel Variables... Starting Remount Root and Kernel File Systems... Mounting Kernel Debug File System... [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Kernel Debug 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. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 12.727592] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Coldplug all Devices. [ OK ] Started udev Kernel Device Manager. [ 13.049888] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.149205] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.208086] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.231246] EDAC sbridge: Ver: 1.1.2 [ 14.311296] Key type dns_resolver registered [ 14.629472] NFS: Registering the id_resolver key type [ 14.631956] Key type id_resolver registered [ 14.633731] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started D-Bus System Message Bus. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. Starting Network Manager... Starting Login Service... [ OK ] Reached target sshd-keygen.target. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started OpenSSH server daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg339-client login: [ 41.810371] libcfs: loading out-of-tree module taints kernel. [ 41.858952] Key type ._llcrypt registered [ 41.860486] Key type .llcrypt registered [ 42.246735] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 42.254677] alg: No test for adler32 (adler32-zlib) [ 43.318930] Lustre: Lustre: Build Version: 2.17.59_3_g21e240e [ 43.688677] LNet: Added LNI 192.168.203.39@tcp [8/256/0/180] [ 45.335219] Key type lgssc registered [ 46.133044] Lustre: Echo OBD driver; http://www.lustre.org/ [ 172.944932] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [ 176.019005] hrtimer: interrupt took 5994229 ns [ 178.057284] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 191.546550] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing check_logdir /tmp/testlogs/ [ 197.245149] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing yml_node [ 198.626028] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 23s idle [ 201.884392] Lustre: DEBUG MARKER: Client: 2.17.59.3 [ 204.411596] Lustre: DEBUG MARKER: MDS: 2.17.59.3 [ 206.933418] Lustre: DEBUG MARKER: OSS: 2.17.59.3 [ 209.284682] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Tue Sep 29 23:47:13 EDT 2026 [ 227.339476] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 228.978765] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 12a 9 [ 231.059758] Lustre: DEBUG MARKER: === sanity-quota: start setup 23:47:35 (1790740055) === [ 235.917381] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing check_config_client /mnt/lustre [ 251.067831] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 262.368276] Lustre: DEBUG MARKER: === sanity-quota: finish setup 23:48:06 (1790740086) === [ 331.596195] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 23:49:15 (1790740155) [ 352.225576] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 20s idle [ 352.230648] Lustre: Skipped 1 previous similar message [ 377.823418] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 22s idle [ 388.072603] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 24s idle [ 397.389652] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 23:50:21 (1790740221) [ 414.416846] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 421.170171] Lustre: DEBUG MARKER: Write... [ 423.738986] Lustre: DEBUG MARKER: Write out of block quota ... [ 439.263358] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 21s idle [ 459.743441] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 23s idle [ 467.166367] Lustre: DEBUG MARKER: -------------------------------------- [ 468.854762] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 475.879577] Lustre: DEBUG MARKER: Write... [ 478.280873] Lustre: DEBUG MARKER: Write out of block quota ... [ 495.584828] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 22s idle [ 530.558633] Lustre: DEBUG MARKER: -------------------------------------- [ 532.766242] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 535.138484] Lustre: DEBUG MARKER: Write... [ 537.829585] Lustre: DEBUG MARKER: Write out of block quota ... [ 551.909843] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 23s idle [ 551.913124] Lustre: Skipped 1 previous similar message [ 604.302767] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 23:53:49 (1790740429) [ 619.715024] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 638.963359] Lustre: DEBUG MARKER: Write... [ 641.679434] Lustre: DEBUG MARKER: Write out of block quota ... [ 659.427807] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 23s idle [ 659.440961] Lustre: Skipped 3 previous similar messages [ 685.641752] Lustre: DEBUG MARKER: -------------------------------------- [ 687.562838] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 694.537292] Lustre: DEBUG MARKER: Write... [ 697.132799] Lustre: DEBUG MARKER: Write out of block quota ... [ 748.563994] Lustre: DEBUG MARKER: -------------------------------------- [ 750.242664] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 753.395803] Lustre: DEBUG MARKER: Write... [ 756.148807] Lustre: DEBUG MARKER: Write out of block quota ... [ 792.547588] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 22s idle [ 792.553660] Lustre: Skipped 4 previous similar messages [ 839.213923] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 23:57:44 (1790740664) [ 857.969873] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 883.506190] Lustre: DEBUG MARKER: Write... [ 887.534544] Lustre: DEBUG MARKER: Write out of block quota ... [ 992.551503] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 00:00:16 (1790740816) [ 1012.770943] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 1040.310978] Lustre: DEBUG MARKER: Write... [ 1043.596756] Lustre: DEBUG MARKER: Write out of block quota ... [ 1058.784288] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 20s idle [ 1058.808741] Lustre: Skipped 7 previous similar messages [ 1146.497329] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 00:02:50 (1790740970) [ 1163.526549] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 1176.141342] Lustre: DEBUG MARKER: Write... [ 1178.899629] Lustre: DEBUG MARKER: Write out of block quota ... [ 1191.092788] Lustre: DEBUG MARKER: Write... [ 1262.032596] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 00:04:46 (1790741086) [ 1278.897400] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1291.302497] Lustre: DEBUG MARKER: Write... [ 1294.075746] Lustre: DEBUG MARKER: Write out of block quota ... [ 1342.894111] Lustre: DEBUG MARKER: Write... [ 1345.841717] Lustre: DEBUG MARKER: Write out of block quota ... [ 1402.833277] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 00:07:07 (1790741227) [ 1419.589123] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 1434.744295] Lustre: DEBUG MARKER: Write... [ 1446.788580] Lustre: DEBUG MARKER: Write out of block quota ... [ 1531.260696] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 00:09:16 (1790741356) [ 1534.322450] Lustre: DEBUG MARKER: SKIP: sanity-quota test_1h fallocate not supported [ 1536.437258] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 00:09:20 (1790741360) [ 1554.415394] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1567.189981] Lustre: DEBUG MARKER: Write... [ 1570.395101] Lustre: DEBUG MARKER: Write out of block quota ... [ 1586.144679] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 21s idle [ 1586.154841] Lustre: Skipped 14 previous similar messages [ 1611.902259] Lustre: DEBUG MARKER: Write... [ 1614.860823] Lustre: DEBUG MARKER: Write out of block quota ... [ 1673.697711] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 00:11:37 (1790741497) [ 1694.927939] Lustre: DEBUG MARKER: -------------------------------------- [ 1696.422409] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 2048.276891] Lustre: DEBUG MARKER: == sanity-quota test 1k: LQA: Block hard limit (normal use and out of quota) ========================================================== 00:17:52 (1790741872) [ 2070.207901] Lustre: DEBUG MARKER: Write... [ 2074.541375] Lustre: DEBUG MARKER: Write out of block quota ... [ 2120.707529] Lustre: DEBUG MARKER: Write... [ 2124.620225] Lustre: DEBUG MARKER: Write out of block quota ... [ 2168.298575] Lustre: DEBUG MARKER: Write... [ 2172.149322] Lustre: DEBUG MARKER: Write out of block quota ... [ 2190.303284] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 24s idle [ 2190.312463] Lustre: Skipped 11 previous similar messages [ 2218.677874] Lustre: DEBUG MARKER: == sanity-quota test 1l: Async writes should not be rejected by quota with root_prj_enable ========================================================== 00:20:43 (1790742043) [ 2219.200748] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [ 2276.327036] Lustre: Unmounted lustre-client [ 2278.392444] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 2281.200156] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 00:21:44 (1790742104) [ 2373.338471] Lustre: DEBUG MARKER: Write after timer goes off [ 2376.573380] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2523.953215] Lustre: DEBUG MARKER: Write after timer goes off [ 2527.428167] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2663.650381] Lustre: DEBUG MARKER: Write after timer goes off [ 2665.908954] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2781.979782] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 00:30:06 (1790742606) [ 2834.914772] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 22s idle [ 2834.930457] Lustre: Skipped 20 previous similar messages [ 2879.963722] Lustre: DEBUG MARKER: Write after timer goes off [ 2882.835897] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3026.620693] Lustre: DEBUG MARKER: Write after timer goes off [ 3029.361580] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3172.369360] Lustre: DEBUG MARKER: Write after timer goes off [ 3174.976290] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3294.728295] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 00:38:39 (1790743119) [ 3400.193397] Lustre: DEBUG MARKER: Write after timer goes off [ 3403.069534] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3449.311649] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 21s idle [ 3449.323789] Lustre: Skipped 22 previous similar messages [ 3504.914552] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 3506.866270] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 00:42:11 (1790743331) [ 3521.374142] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 3656.440889] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 00:44:41 (1790743481) [ 3812.396613] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 00:47:16 (1790743636) [ 3848.677929] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection to lustre-OST0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3863.661411] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 4045.120103] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 00:51:09 (1790743869) [ 4084.193232] Lustre: lustre-OST0001-osc-ffff9c7c83efd000: disconnect after 24s idle [ 4084.211989] Lustre: Skipped 9 previous similar messages [ 4094.442454] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection to lustre-OST0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4103.717575] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 4209.106502] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 00:53:53 (1790744033) [ 4258.279422] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [ 4258.305254] Lustre: lustre-MDT0000-mdc-ffff9c7c83efd000: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4258.311804] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a816423b49 to 0x129271a8164b6cb5 [ 4258.398762] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 4259.359694] Lustre: 2350:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790744069/real 1790744069] req@ffff9c7c84730e00 x1877726855435392/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c83efd000@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790744085 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4264.543169] Lustre: 2350:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790744074/real 1790744074] req@ffff9c7c84731180 x1877726855435904/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c83efd000@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790744090 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4269.535332] Lustre: 2352:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790744079/real 1790744079] req@ffff9c7c98d83800 x1877726855436416/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c83efd000@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790744095 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4425.755813] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 00:57:30 (1790744250) [ 4518.112653] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 00:59:02 (1790744342) [ 4519.758701] Lustre: DEBUG MARKER: SKIP: sanity-quota test_7e needs >= 2 MDTs [ 4521.448246] Lustre: DEBUG MARKER: == sanity-quota test 7f: Quota reintegration automatically ========================================================== 00:59:06 (1790744346) [ 4739.553214] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: disconnect after 22s idle [ 4739.562651] Lustre: Skipped 12 previous similar messages [ 4752.940081] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 01:02:57 (1790744577) [ 4958.802859] Lustre: DEBUG MARKER: SKIP: sanity-quota test_9 skipping SLOW test 9 [ 4960.851652] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 01:06:25 (1790744785) [ 5018.179623] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 01:07:22 (1790744842) [ 5071.216564] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12a skipping SLOW test 12a [ 5073.166685] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 01:08:17 (1790744897) [ 5074.940654] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12b needs >= 2 MDTs [ 5076.867712] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 01:08:21 (1790744901) [ 5152.193243] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 01:09:36 (1790744976) [ 5179.878473] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection to lustre-OST0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5195.873387] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 5195.886170] Lustre: Skipped 1 previous similar message [ 5242.914417] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 01:11:07 (1790745067) [ 5277.189925] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 01:11:41 (1790745101) [ 5294.693759] Lustre: setting import lustre-OST0000_UUID INACTIVE by administrator request [ 5301.544127] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection to lustre-OST0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5301.585163] LustreError: lustre-OST0000-osc-ffff9c7c83efd000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 5301.606895] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 5328.707491] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 01:12:33 (1790745153) [ 5330.678964] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 5332.967894] Lustre: DEBUG MARKER: == sanity-quota test 16c: lfs quota should preserve usage with an unavailable OST ========================================================== 01:12:37 (1790745157) [ 5366.255949] Lustre: lustre-OST0000-osc-ffff9c7c83efd000: Connection to lustre-OST0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5369.974576] Lustre: Unmounted lustre-client [ 5370.437394] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [ 5376.640431] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state (DISCONN|IDLE) osc.lustre-OST0000-osc-ffff9c7c8682a800.ost_server_uuid 50 [ 5378.264961] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9c7c8682a800.ost_server_uuid in DISCONN state after 0 sec [ 5378.372873] LustreError: 105715:0:(lov_obd.c:1344:lov_quotactl()) lustre-clilov-ffff9c7c8682a800: ost 0 is inactive: rc = -100 [ 5387.159418] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5390.850223] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5395.965838] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5401.082784] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5406.200704] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5416.462621] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5416.470737] LustreError: Skipped 1 previous similar message [ 5436.928158] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5436.940685] LustreError: Skipped 3 previous similar messages [ 5472.794550] LustreError: lustre-OST0000-osc-ffff9c7c8682a800: operation ost_connect to node 192.168.203.139@tcp failed: rc = -16 [ 5472.812393] LustreError: Skipped 6 previous similar messages [ 5501.867884] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9c7c8682a800.ost_server_uuid 50 [ 5503.906906] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9c7c8682a800.ost_server_uuid in FULL state after 0 sec [ 5536.053993] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 01:16:00 (1790745360) [ 5887.959713] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 01:21:52 (1790745712) [ 5906.955966] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5913.103486] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 5917.188202] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5919.029282] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5939.679723] Lustre: 2352:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790745749/real 1790745749] req@ffff9c7c98c94000 x1877726860110592/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c8682a800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790745765 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5939.698475] Lustre: lustre-MDT0000-mdc-ffff9c7c8682a800: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5939.704850] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [ 5939.723313] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a8164fddfd to 0x129271a8164fea8a [ 5939.734357] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 5941.479346] Lustre: 105289:0:(mgc_request.c:1900:mgc_process_log()) MGC192.168.203.139@tcp: IR log lustre-cliir failed, not fatal: rc = -2 [ 5944.800351] Lustre: 2351:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790745754/real 1790745754] req@ffff9c7c84799880 x1877726860111104/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c8682a800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790745770 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5944.870215] Lustre: 2351:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5949.024126] Lustre: 2351:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790745759/real 1790745759] req@ffff9c7c84799180 x1877726860111616/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c8682a800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790745775 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5954.406289] Lustre: 2353:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790745764/real 1790745764] req@ffff9c7c985ad880 x1877726860112128/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c8682a800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790745780 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5964.384324] Lustre: lustre-MDT0000-mdc-ffff9c7c8682a800: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 5970.485796] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5972.264110] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5978.267817] Lustre: DEBUG MARKER: (dd_pid=117142, time=0, timeout=600) [ 6022.513403] Lustre: DEBUG MARKER: User quota (limit: 200) [ 6028.953228] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 6033.046576] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6034.703625] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 6056.430344] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [ 6056.455586] Lustre: lustre-MDT0000-mdc-ffff9c7c8682a800: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6056.485312] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a8164fea8a to 0x129271a8164ff454 [ 6056.506426] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [ 6056.538982] LustreError: 2349:0:(client.c:3449:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff9c7c98c94a80 x1877726860133632/t12884901902(12884901902) o101->lustre-MDT0000-mdc-ffff9c7c8682a800@192.168.203.139@tcp:12/10 lens 592/608 e 0 to 0 dl 1790745898 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 6057.506168] Lustre: 2353:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790745867/real 1790745867] req@ffff9c7c985ae680 x1877726860144640/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c8682a800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790745883 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6067.679170] Lustre: 2350:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790745877/real 1790745877] req@ffff9c7c869fe680 x1877726860145792/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c8682a800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790745893 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6067.728692] Lustre: 2350:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 6070.917936] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 6072.632747] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6081.014971] Lustre: DEBUG MARKER: (dd_pid=119582, time=3, timeout=600) [ 6146.230818] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 01:26:11 (1790745971) [ 6169.415098] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 6171.114072] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:1). [ 6177.214438] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 6178.851162] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:1). [ 6214.304938] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 01:27:19 (1790746039) [ 6236.916763] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 6253.409710] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 6255.805158] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 6257.686478] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 6260.191702] Lustre: DEBUG MARKER: Set quota for 1 times [ 6264.042484] Lustre: DEBUG MARKER: Set quota for 2 times [ 6268.268159] Lustre: DEBUG MARKER: Set quota for 3 times [ 6272.180403] Lustre: DEBUG MARKER: Set quota for 4 times [ 6276.387810] Lustre: DEBUG MARKER: Set quota for 5 times [ 6280.191879] Lustre: DEBUG MARKER: Set quota for 6 times [ 6284.082669] Lustre: DEBUG MARKER: Set quota for 7 times [ 6287.895306] Lustre: DEBUG MARKER: Set quota for 8 times [ 6330.718868] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 01:29:15 (1790746155) [ 6340.046394] Lustre: Unmounted lustre-client [ 6433.274447] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [ 6438.717476] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6455.932132] Lustre: Unmounted lustre-client [ 6534.376522] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [ 6538.793311] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6551.317346] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 01:32:56 (1790746376) [ 6553.009404] Lustre: DEBUG MARKER: SKIP: sanity-quota test_23 Overwrite in place is not guaranteed to be space neutral on ZFS [ 6554.734243] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 01:32:59 (1790746379) [ 6560.223309] Lustre: lustre-OST0000-osc-ffff9c7c918a9800: disconnect after 24s idle [ 6560.228795] Lustre: Skipped 13 previous similar messages [ 6612.925508] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 01:33:57 (1790746437) [ 6662.852921] Lustre: DEBUG MARKER: Write... [ 6665.434792] Lustre: DEBUG MARKER: Write out of block quota ... [ 6683.103336] Lustre: lustre-OST0000-osc-ffff9c7c918a9800: disconnect after 22s idle [ 6683.109096] Lustre: Skipped 3 previous similar messages [ 6720.704832] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 01:35:45 (1790746545) [ 6727.129256] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 01:35:51 (1790746551) [ 6737.547460] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 01:36:01 (1790746561) [ 6746.932439] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 01:36:11 (1790746571) [ 6755.038755] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 01:36:19 (1790746579) [ 6822.937950] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 6872.551952] Lustre: lustre-OST0000-osc-ffff9c7c918a9800: disconnect after 22s idle [ 6872.563617] Lustre: Skipped 5 previous similar messages [ 6983.997612] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 7171.603695] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 01:43:15 (1790746995) [ 7205.343867] Lustre: lustre-OST0000-osc-ffff9c7c918a9800: disconnect after 23s idle [ 7205.347833] Lustre: Skipped 10 previous similar messages [ 7235.158041] Lustre: DEBUG MARKER: Restart... [ 7237.568281] Lustre: Unmounted lustre-client [ 7320.841889] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [ 7326.267834] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7404.637421] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 01:47:08 (1790747228) [ 7487.042804] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 01:48:31 (1790747311) [ 9051.619376] Lustre: lustre-OST0000-osc-ffff9c7c84496000: disconnect after 23s idle [ 9051.640521] Lustre: Skipped 5 previous similar messages [ 9366.737354] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 02:19:51 (1790749191) [ 9379.027797] Lustre: Unmounted lustre-client [ 9466.942133] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [ 9472.400440] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 9492.448578] Lustre: lustre-OST0001-osc-ffff9c7c918ad000: disconnect after 23s idle [ 9492.458400] Lustre: Skipped 1 previous similar message [ 9514.308708] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 02:22:18 (1790749338) [ 9561.021573] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 02:23:05 (1790749385) [ 9607.275174] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 02:23:51 (1790749431) [ 9608.877681] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40c needs >= 2 MDTs [ 9611.081228] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 02:23:55 (1790749435) [ 9612.770425] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40d needs >= 2 MDTs [ 9614.701934] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 02:23:59 (1790749439) [ 9697.247430] Lustre: lustre-OST0000-osc-ffff9c7c918ad000: disconnect after 24s idle [ 9697.259691] Lustre: Skipped 5 previous similar messages [ 9704.445474] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 02:25:28 (1790749528) [ 9759.517425] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 02:26:23 (1790749583) [ 9854.471640] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 02:27:58 (1790749678) [10209.248512] Lustre: lustre-OST0000-osc-ffff9c7c918ad000: disconnect after 23s idle [10209.257636] Lustre: Skipped 5 previous similar messages [10698.797904] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [10709.119418] Lustre: Unmounted lustre-client [10858.314771] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [10864.763403] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10884.064985] Lustre: lustre-OST0000-osc-ffff9c7c847eb000: disconnect after 23s idle [10884.086650] Lustre: Skipped 3 previous similar messages [10908.040990] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 02:45:32 (1790750732) [10914.721904] Lustre: DEBUG MARKER: == sanity-quota test 49c: lfs quota long options don't consume an extra argument ========================================================== 02:45:39 (1790750739) [10923.492555] Lustre: DEBUG MARKER: == sanity-quota test 49d: lfs quota -d and --delimiter both work ========================================================== 02:45:47 (1790750747) [10931.924368] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 02:45:56 (1790750756) [10983.934382] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 02:46:48 (1790750808) [11048.192589] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 02:47:53 (1790750873) [11080.538624] Lustre: DEBUG MARKER: rename directory return 255 [11130.316076] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 02:49:14 (1790750954) [11162.879568] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 02:49:47 (1790750987) [11207.766582] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 02:50:32 (1790751032) [11309.939483] LustreError: 222486:0:(llite_lib.c:2160:ll_md_setattr()) md_setattr fails: rc = -122 [11349.630632] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 02:52:54 (1790751174) [11389.764413] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 02:53:34 (1790751214) [11438.409575] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 02:54:22 (1790751262) [11519.514290] LustreError: 228077:0:(file.c:252:ll_close_inode_openhandle()) lustre-clilmv-ffff9c7c847eb000: inode [0x200000401:0xad:0x0] mdc close failed: rc = -22 [11539.427195] Lustre: lustre-OST0000-osc-ffff9c7c847eb000: disconnect after 21s idle [11539.440430] Lustre: Skipped 11 previous similar messages [11605.394700] LustreError: 229455:0:(file.c:252:ll_close_inode_openhandle()) lustre-clilmv-ffff9c7c847eb000: inode [0x200000401:0xad:0x0] mdc close failed: rc = -22 [11605.404332] LustreError: 229455:0:(file.c:252:ll_close_inode_openhandle()) Skipped 1 previous similar message [11644.926473] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 02:57:49 (1790751469) [11646.688829] Lustre: DEBUG MARKER: SKIP: sanity-quota test_59 ldiskfs only test [11648.878532] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 02:57:53 (1790751473) [11714.745555] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [11716.594980] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 02:59:01 (1790751541) [11752.584663] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [11754.782208] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 02:59:39 (1790751579) [11812.367318] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [11814.433640] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 03:00:38 (1790751638) [11865.686710] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 03:01:30 (1790751690) [11867.635774] Lustre: DEBUG MARKER: SKIP: sanity-quota test_67 ZFS grants some block space together with inode [11869.955913] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 03:01:34 (1790751694) [11946.106685] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 03:02:50 (1790751770) [11974.457528] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [11976.770665] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [12174.303590] Lustre: lustre-OST0000-osc-ffff9c7c847eb000: disconnect after 22s idle [12174.316541] Lustre: Skipped 8 previous similar messages [12181.504520] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 03:06:46 (1790752006) [12234.628396] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 03:07:38 (1790752058) [12270.147824] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 03:08:14 (1790752094) [12271.805634] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71a ZFS grants some block space together with inode [12273.723904] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 03:08:18 (1790752098) [12275.636129] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71b ZFS grants some block space together with inode [12277.670260] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 03:08:22 (1790752102) [12295.129874] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [12312.812147] Lustre: DEBUG MARKER: Write... [12316.071253] Lustre: DEBUG MARKER: Write out of block quota ... [12379.770412] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 03:10:04 (1790752204) [12407.416335] Lustre: DEBUG MARKER: set to use default quota [12409.700617] Lustre: DEBUG MARKER: set default quota [12412.266763] Lustre: DEBUG MARKER: get default quota [12420.741792] Lustre: DEBUG MARKER: Test not out of quota [12428.072737] Lustre: DEBUG MARKER: Test out of quota [12439.021649] Lustre: DEBUG MARKER: Increase default quota [12468.612458] Lustre: DEBUG MARKER: Set quota to override default quota [12481.615498] Lustre: DEBUG MARKER: Set to use default quota again [12503.684740] Lustre: DEBUG MARKER: Cleanup [12576.905504] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 03:13:21 (1790752401) [12600.901266] Lustre: DEBUG MARKER: set default quota for qpool1 [12603.258114] Lustre: DEBUG MARKER: Write from user that hasn't lqe [12656.293249] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 03:14:40 (1790752480) [12743.203491] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 03:16:07 (1790752567) [12788.703896] Lustre: lustre-OST0000-osc-ffff9c7c847eb000: disconnect after 23s idle [12788.719277] Lustre: Skipped 10 previous similar messages [12821.354890] Lustre: DEBUG MARKER: Write... [12824.921552] Lustre: DEBUG MARKER: Write out of block quota ... [12944.117728] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 03:19:28 (1790752768) [12994.075426] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 03:20:18 (1790752818) [12994.646778] Lustre: Mounted lustre-client read-only - version 2.17.59_3_g21e240e [12994.979625] Lustre: Unmounted lustre-client [13002.312315] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 03:20:26 (1790752826) [13005.673048] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78A fallocate not supported [13007.628258] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 03:20:32 (1790752832) [13010.845847] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78a fallocate not supported [13012.911522] Lustre: DEBUG MARKER: == sanity-quota test 78b: fallocate restart preallocates the whole requested range ========================================================== 03:20:37 (1790752837) [13014.948619] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78b fallocate restart is ldiskfs only [13017.437935] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 03:20:41 (1790752841) [13038.197825] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 03:21:02 (1790752862) [13039.753631] Lustre: DEBUG MARKER: SKIP: sanity-quota test_80 ZFS grants some block space together with inode [13041.489863] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 03:21:06 (1790752866) [13058.387369] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [13071.333574] Lustre: lustre-MDT0000-mdc-ffff9c7c847eb000: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [13086.694985] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [13086.711802] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a8167100b4 to 0x129271a816722a2d [13086.717865] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [13086.723990] Lustre: Skipped 1 previous similar message [13091.916384] LustreError: lustre-MDT0000-mdc-ffff9c7c847eb000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13091.943267] Lustre: lustre-MDT0000-mdc-ffff9c7c847eb000: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [13122.737335] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 03:22:27 (1790752947) [13156.126834] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 03:23:00 (1790752980) [13187.050629] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 03:23:31 (1790753011) [13348.242776] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 03:26:12 (1790753172) [13399.011873] Lustre: lustre-OST0000-osc-ffff9c7c847eb000: disconnect after 22s idle [13399.024188] Lustre: Skipped 16 previous similar messages [13431.348296] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 03:27:36 (1790753256) [13986.166186] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 03:36:50 (1790753810) [14064.607276] Lustre: lustre-OST0000-osc-ffff9c7c847eb000: disconnect after 23s idle [14064.617748] Lustre: Skipped 1 previous similar message [14105.589506] Lustre: lustre-MDT0000-mdc-ffff9c7c847eb000: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [14120.943422] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [14120.996033] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a816722a2d to 0x129271a81682562f [14121.018411] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [14125.198865] LustreError: lustre-MDT0000-mdc-ffff9c7c847eb000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14125.221780] Lustre: lustre-MDT0000-mdc-ffff9c7c847eb000: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [14148.425797] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 03:39:33 (1790753973) [14149.980718] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [14151.881671] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 03:39:36 (1790753976) [14161.566381] LustreError: 278038:0:(mdc_request.c:2191:mdc_quotactl()) lustre-MDT0000-mdc-ffff9c7c847eb000: ptlrpc_queue_wait failed: rc = -1 [14173.614283] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 03:39:58 (1790753998) [14195.999295] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 03:40:20 (1790754020) [14209.903503] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [14218.284987] Lustre: Unmounted lustre-client [14220.017867] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 03:40:44 (1790754044) [14222.240792] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [14222.248344] Lustre: Skipped 2 previous similar messages [14232.536653] Lustre: Unmounted lustre-client [14333.352204] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [14357.259580] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [14382.106883] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [14382.946967] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [14413.822651] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [14413.859924] Lustre: lustre-MDT0000-mdc-ffff9c7ca0ace800: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [14413.892367] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a816825adc to 0x129271a816825dec [14413.924032] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [14413.962386] LustreError: lustre-MDT0000-mdc-ffff9c7ca0ace800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14421.759733] Lustre: DEBUG MARKER: oleg339-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [14423.616454] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [14431.402263] Lustre: Unmounted lustre-client [14579.386365] Lustre: Mounted lustre-client - version 2.17.59_3_g21e240e [14585.227604] Lustre: DEBUG MARKER: Using TIMEOUT=20 [14596.067809] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 03:47:00 (1790754420) [14611.381020] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 03:47:16 (1790754436) [14687.199269] Lustre: lustre-OST0000-osc-ffff9c7c90ea5800: disconnect after 21s idle [14687.213967] Lustre: Skipped 9 previous similar messages [14702.439646] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 03:48:47 (1790754527) [14743.530211] Lustre: lustre-MDT0000-mdc-ffff9c7c90ea5800: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [14758.909336] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [14758.933234] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a8168261c7 to 0x129271a816826842 [14758.946575] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [14758.962382] Lustre: Skipped 1 previous similar message [14763.167855] LustreError: lustre-MDT0000-mdc-ffff9c7c90ea5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14763.196627] Lustre: lustre-MDT0000-mdc-ffff9c7c90ea5800: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [14773.222712] Lustre: lustre-MDT0000-mdc-ffff9c7c90ea5800: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [14788.590385] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [14788.623265] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a816826842 to 0x129271a816826992 [14788.644471] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [14803.068554] LustreError: lustre-MDT0000-mdc-ffff9c7c90ea5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14805.129474] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 03:50:29 (1790754629) [14835.328713] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 03:50:59 (1790754659) [14884.982952] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 03:51:49 (1790754709) [14886.874633] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 the test in only needed to run on LDiskFS [14888.736523] Lustre: DEBUG MARKER: == sanity-quota test 97a: LQA control commands =========== 03:51:53 (1790754713) [14920.178427] Lustre: DEBUG MARKER: == sanity-quota test 97b: Check LQA internals ============ 03:52:24 (1790754744) [14957.917283] Lustre: DEBUG MARKER: adding 50 LQA ranges took 1s [14963.162475] Lustre: DEBUG MARKER: Removing 50 LQA ranges took 2s [14972.962875] Lustre: DEBUG MARKER: == sanity-quota test 97c: LQA lfs quota commands and MDS restart consistency ========================================================== 03:53:17 (1790754797) [14987.244132] Lustre: lustre-MDT0000-mdc-ffff9c7c90ea5800: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [14987.249782] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [14987.311165] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a816826992 to 0x129271a816827006 [14987.339168] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [14987.352516] Lustre: Skipped 1 previous similar message [14998.495159] Lustre: 2350:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790754808/real 1790754808] req@ffff9c7c901ece00 x1877726900058240/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c90ea5800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790754824 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [15007.654857] Lustre: DEBUG MARKER: == sanity-quota test 97d: LQA disk persistence using standard commands ========================================================== 03:53:52 (1790754832) [15043.566324] LustreError: MGC192.168.203.139@tcp: Connection to MGS (at 192.168.203.139@tcp) was lost; in progress operations using this service will fail [15043.597524] Lustre: lustre-MDT0000-mdc-ffff9c7c90ea5800: Connection to lustre-MDT0000 (at 192.168.203.139@tcp) was lost; in progress operations using this service will wait for recovery to complete [15043.630090] Lustre: Evicted from MGS (at 192.168.203.139@tcp) after server handle changed from 0x129271a816827006 to 0x129271a81682738d [15043.657332] Lustre: MGC192.168.203.139@tcp: Connection restored to 192.168.203.139@tcp (at 192.168.203.139@tcp) [15043.673686] Lustre: Skipped 1 previous similar message [15049.503215] Lustre: 2352:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790754859/real 1790754859] req@ffff9c7c908cc700 x1877726900064128/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c90ea5800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790754875 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [15054.819419] Lustre: 2353:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1790754864/real 1790754864] req@ffff9c7c85089880 x1877726900064384/t0(0) o400->lustre-MDT0000-mdc-ffff9c7c90ea5800@192.168.203.139@tcp:12/10 lens 224/224 e 0 to 1 dl 1790754880 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [15107.872402] Lustre: DEBUG MARKER: == sanity-quota test 97e: LQA add/remove should reject invalid ranges ========================================================== 03:55:32 (1790754932) [15123.164448] Lustre: DEBUG MARKER: == sanity-quota test 98: Verify MDT retry on -EDQUOT during mkdir ========================================================== 03:55:47 (1790754947) [15125.240960] Lustre: DEBUG MARKER: SKIP: sanity-quota test_98 needs >= 2 MDTs [15126.919708] Lustre: DEBUG MARKER: == sanity-quota test 300: inode quota with MDT directory migration at 80% limit ========================================================== 03:55:51 (1790754951) [15128.692355] Lustre: DEBUG MARKER: SKIP: sanity-quota test_300 needs >= 2 MDTs [15133.346858] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 14923 sec ======== 03:55:58 (1790754958) [15135.139883] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 03:55:59 (1790754959) === [15138.676778] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 03:56:03 (1790754963) === [15140.921395] Lustre: Unmounted lustre-client [15161.630866] Key type lgssc unregistered [15161.969439] LNet: 303022:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [15161.980842] LNetError: 303022:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [15162.011952] LNet: Removed LNI 192.168.203.39@tcp [15162.970167] Key type .llcrypt unregistered [15162.973658] Key type ._llcrypt unregistered