[ 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 454100301 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2464 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2300 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022C0 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2374 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE2404 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE243C 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2300-0xbffe2373] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22ff] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2374-0xbffe2403] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe2404-0xbffe243b] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe243c-0xbffe2463] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059618 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829700K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001015] APIC: Switch to symmetric I/O mode setup [ 0.003243] x2apic enabled [ 0.004010] Switched APIC routing to physical x2apic. [ 0.005020] kvm-guest: setup PV IPIs [ 0.007899] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008031] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009018] pid_max: default: 32768 minimum: 301 [ 0.010152] LSM: Security Framework initializing [ 0.011077] Yama: becoming mindful. [ 0.012043] SELinux: Initializing. [ 0.013110] *** VALIDATE selinux *** [ 0.021114] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026090] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028162] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029133] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031041] *** VALIDATE tmpfs *** [ 0.032520] *** VALIDATE proc *** [ 0.033307] *** VALIDATE cgroup *** [ 0.034017] *** VALIDATE cgroup2 *** [ 0.036007] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037173] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.038014] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.039037] Spectre V2 : User space: Vulnerable [ 0.040011] Speculative Store Bypass: Vulnerable [ 0.043174] debug: unmapping init [mem 0xffffffffaa459000-0xffffffffaa460fff] [ 0.046000] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046773] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.047034] ... version: 2 [ 0.048016] ... bit width: 48 [ 0.049015] ... generic registers: 4 [ 0.049943] ... value mask: 0000ffffffffffff [ 0.050017] ... max period: 00007fffffffffff [ 0.051017] ... fixed-purpose events: 3 [ 0.052015] ... event mask: 000000070000000f [ 0.053332] rcu: Hierarchical SRCU implementation. [ 0.055572] smp: Bringing up secondary CPUs ... [ 0.056495] x86: Booting SMP configuration: [ 0.057034] .... node #0, CPUs: #1 #2 #3 [ 0.061403] smp: Brought up 1 node, 4 CPUs [ 0.062940] smpboot: Max logical packages: 1 [ 0.063013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.224054] node 0 deferred pages initialised in 158ms [ 0.229595] devtmpfs: initialized [ 0.231293] x86/mm: Memory block size: 128MB [ 0.233909] gcov: version magic: 0x41383552 [ 0.236210] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.239096] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.243339] pinctrl core: initialized pinctrl subsystem [ 0.245155] [ 0.245596] ************************************************************* [ 0.247012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.249019] ** ** [ 0.251019] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.253012] ** ** [ 0.255012] ** This means that this kernel is built to expose internal ** [ 0.257014] ** IOMMU data structures, which may compromise security on ** [ 0.259015] ** your system. ** [ 0.262014] ** ** [ 0.264014] ** If you see this message and you are not debugging the ** [ 0.266016] ** kernel, report this immediately to your vendor! ** [ 0.268026] ** ** [ 0.270016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.272021] ************************************************************* [ 0.275363] NET: Registered protocol family 16 [ 0.277481] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.279069] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.282072] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.285124] cpuidle: using governor menu [ 0.287468] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.290723] PCI: Using configuration type 1 for base access [ 0.293146] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.302128] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.305038] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.308152] cryptd: max_cpu_qlen set to 1000 [ 0.311234] ACPI: Added _OSI(Module Device) [ 0.313017] ACPI: Added _OSI(Processor Device) [ 0.314013] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.315014] ACPI: Added _OSI(Processor Aggregator Device) [ 0.320188] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.326539] ACPI: Interpreter enabled [ 0.327076] ACPI: PM: (supports S0 S3 S4 S5) [ 0.329015] ACPI: Using IOAPIC for interrupt routing [ 0.330113] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.333426] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.343577] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.346052] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.348024] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.352113] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.357478] acpiphp: Slot [2] registered [ 0.359163] acpiphp: Slot [5] registered [ 0.360177] acpiphp: Slot [6] registered [ 0.362190] acpiphp: Slot [3] registered [ 0.363122] acpiphp: Slot [4] registered [ 0.365122] acpiphp: Slot [7] registered [ 0.366123] acpiphp: Slot [8] registered [ 0.368113] acpiphp: Slot [9] registered [ 0.369072] acpiphp: Slot [10] registered [ 0.370101] acpiphp: Slot [11] registered [ 0.372123] acpiphp: Slot [12] registered [ 0.373112] acpiphp: Slot [13] registered [ 0.375104] acpiphp: Slot [14] registered [ 0.376124] acpiphp: Slot [15] registered [ 0.378123] acpiphp: Slot [16] registered [ 0.379164] acpiphp: Slot [17] registered [ 0.381129] acpiphp: Slot [18] registered [ 0.382099] acpiphp: Slot [19] registered [ 0.383101] acpiphp: Slot [20] registered [ 0.384091] acpiphp: Slot [21] registered [ 0.386123] acpiphp: Slot [22] registered [ 0.387106] acpiphp: Slot [23] registered [ 0.389153] acpiphp: Slot [24] registered [ 0.390115] acpiphp: Slot [25] registered [ 0.392096] acpiphp: Slot [26] registered [ 0.393082] acpiphp: Slot [27] registered [ 0.394098] acpiphp: Slot [28] registered [ 0.396114] acpiphp: Slot [29] registered [ 0.397146] acpiphp: Slot [30] registered [ 0.399123] acpiphp: Slot [31] registered [ 0.400065] PCI host bridge to bus 0000:00 [ 0.402028] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.404030] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.407040] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.410040] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.412028] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.415036] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.417186] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.421115] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.424174] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.430020] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.433937] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.436025] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.438023] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.441025] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.443287] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.447153] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.449052] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.452888] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.456996] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.466704] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.471017] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.477303] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.481016] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.488023] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.500025] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.508454] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.520022] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.525019] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.536022] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.546869] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.549470] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.552413] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.555417] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.557289] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.562106] iommu: Default domain type: Passthrough [ 0.563481] SCSI subsystem initialized [ 0.565135] ACPI: bus type USB registered [ 0.566083] usbcore: registered new interface driver usbfs [ 0.568082] usbcore: registered new interface driver hub [ 0.569071] usbcore: registered new device driver usb [ 0.570154] pps_core: LinuxPPS API ver. 1 registered [ 0.572012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.575076] PTP clock support registered [ 0.577154] EDAC MC: Ver: 3.0.0 [ 0.579145] PCI: Using ACPI for IRQ routing [ 0.580588] NetLabel: Initializing [ 0.582020] NetLabel: domain hash size = 128 [ 0.583008] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.585084] NetLabel: unlabeled traffic allowed by default [ 0.588044] vgaarb: loaded [ 0.589252] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.590011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.595454] clocksource: Switched to clocksource kvm-clock [ 0.693820] VFS: Disk quotas dquot_6.6.0 [ 0.695376] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.700049] *** VALIDATE ramfs *** [ 0.701138] *** VALIDATE hugetlbfs *** [ 0.702637] pnp: PnP ACPI init [ 0.705151] pnp: PnP ACPI: found 6 devices [ 0.744991] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.748479] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.750731] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.752928] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.755417] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.758640] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.761275] NET: Registered protocol family 2 [ 0.764294] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.769093] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.772449] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.777181] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.780744] TCP: Hash tables configured (established 65536 bind 65536) [ 0.783600] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.786862] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.789414] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.792778] NET: Registered protocol family 1 [ 0.795879] RPC: Registered named UNIX socket transport module. [ 0.797737] RPC: Registered udp transport module. [ 0.799309] RPC: Registered tcp transport module. [ 0.801073] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.803298] NET: Registered protocol family 44 [ 0.805222] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.806555] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.808201] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.810601] PCI: CLS 0 bytes, default 64 [ 0.812312] Unpacking initramfs... [ 2.227369] debug: unmapping init [mem 0xffff93193cc64000-0xffff93193ffcffff] [ 2.232149] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.233798] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.237260] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.718564] Initialise system trusted keyrings [ 2.720330] Key type blacklist registered [ 2.722083] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.730321] zbud: loaded [ 2.734831] *** VALIDATE nfs *** [ 2.735631] *** VALIDATE nfs4 *** [ 2.736712] pstore: using deflate compression [ 2.741333] Platform Keyring initialized [ 2.825062] NET: Registered protocol family 38 [ 2.826540] Key type asymmetric registered [ 2.827529] Asymmetric key parser 'x509' registered [ 2.828911] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.830919] io scheduler mq-deadline registered [ 2.832397] io scheduler kyber registered [ 2.833419] io scheduler bfq registered [ 2.834619] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.837415] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.839717] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.841996] ACPI: Power Button [PWRF] [ 2.846604] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.852700] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.861288] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.887425] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.914432] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.920643] Non-volatile memory driver v1.3 [ 2.922166] Linux agpgart interface v0.103 [ 2.981941] virtio_blk virtio1: [vda] 134864 512-byte logical blocks (69.1 MB/65.9 MiB) [ 2.984709] vda: detected capacity change from 0 to 69050368 [ 2.998794] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.001658] vdb: detected capacity change from 0 to 1073741824 [ 3.007333] libphy: Fixed MDIO Bus: probed [ 3.021953] usbcore: registered new interface driver usbserial_generic [ 3.023539] usbserial: USB Serial support registered for generic [ 3.025437] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.029133] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.030797] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.032897] mousedev: PS/2 mouse device common for all mice [ 3.035713] rtc_cmos 00:05: RTC can wake from S4 [ 3.041492] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.041719] rtc_cmos 00:05: registered as rtc0 [ 3.048462] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.050532] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.051329] intel_pstate: CPU model not supported [ 3.056078] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.059573] hid: raw HID events driver (C) Jiri Kosina [ 3.061462] usbcore: registered new interface driver usbhid [ 3.062822] usbhid: USB HID core driver [ 3.064077] drop_monitor: Initializing network drop monitor service [ 3.066133] Initializing XFRM netlink socket [ 3.067635] NET: Registered protocol family 10 [ 3.069833] Segment Routing with IPv6 [ 3.071262] NET: Registered protocol family 17 [ 3.073058] mpls_gso: MPLS GSO support [ 3.078672] RAS: Correctable Errors collector initialized. [ 3.081148] AVX version of gcm_enc/dec engaged. [ 3.082651] AES CTR mode by8 optimization enabled [ 3.155650] sched_clock: Marking stable (3155519335, 0)->(4095662536, -940143201) [ 3.158825] registered taskstats version 1 [ 3.160880] Loading compiled-in X.509 certificates [ 3.165032] zswap: loaded using pool lzo/zbud [ 3.188841] Key type big_key registered [ 3.200940] Key type encrypted registered [ 3.202097] ima: No TPM chip found, activating TPM-bypass! [ 3.203926] ima: Allocated hash algorithm: sha1 [ 3.205590] ima: No architecture policies found [ 3.207184] evm: Initialising EVM extended attributes: [ 3.208953] evm: security.selinux [ 3.210101] evm: security.ima [ 3.211159] evm: security.capability [ 3.212353] evm: HMAC attrs: 0x1 [ 3.215249] rtc_cmos 00:05: setting system clock to 2026-06-01 15:13:19 UTC (1780326799) [ 3.220966] debug: unmapping init [mem 0xffffffffab403000-0xffffffffab5fffff] [ 3.224113] debug: unmapping init [mem 0xffffffffaa182000-0xffffffffaa458fff] [ 3.234082] Write protecting the kernel read-only data: 28672k [ 3.236952] debug: unmapping init [mem 0xffffffffa8803000-0xffffffffa89fffff] [ 3.239561] debug: unmapping init [mem 0xffffffffa9114000-0xffffffffa91fffff] [ 3.270244] 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.278063] systemd[1]: Detected virtualization kvm. [ 3.279775] systemd[1]: Detected architecture x86-64. [ 3.281490] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.304385] systemd[1]: No hostname configured. [ 3.305986] systemd[1]: Set hostname to . [ 3.307836] random: systemd: uninitialized urandom read (16 bytes read) [ 3.309810] systemd[1]: Initializing machine ID from random generator. [ 3.440107] random: systemd: uninitialized urandom read (16 bytes read) [ 3.443702] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 3.449322] random: systemd: uninitialized urandom read (16 bytes read) [ 3.451520] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 3.456346] systemd[1]: Reached target Local Encrypted Volumes. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Slices. [ OK ] Reached target Timers. [ OK ] Listening on udev Control Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... [ OK ] Reached target Swap. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Sockets. [ OK ] Reached target Local File Systems. Starting Apply Kernel Variables... [ OK ] Reached target Paths. [ OK ] Started Memstrack Anylazing Service. Starting Create Volatile Files and Directories... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.042605] device-mapper: uevent: version 1.0.3 [ 4.044850] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 4.756081] virtio_net virtio0 ens2: renamed from eth0 [ 4.772259] scsi host0: ata_piix [ 4.788842] scsi host1: ata_piix [ 4.790385] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 4.792868] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 9.009288] dracut-initqueue[597]: RTNETLINK answers: File exists [ 9.744885] random: crng init done [ 9.746039] 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.121112] 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 Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev 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.520282] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.919585] SELinux: Disabled at runtime. [ 11.981103] 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.987605] systemd[1]: Detected virtualization kvm. [ 11.989122] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.601600] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.605137] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.616665] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.623193] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.628166] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.637499] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.659026] systemd[1]: Listening on RPCbind Server Activation Socket. [ OK ] Listening on RPCbind Server Activation Socket. Mounting Kernel Debug File System... Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Remount Root a[ 12.974749] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS nd Kernel File Systems... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Created slice system-getty.slice. [ OK ] Reached target rpc_pipefs.target. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on udev Kernel Socket. Starting Apply Kernel Variables... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... Mounting Huge Pages File System... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target RPC Port Mapper. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Reached target Paths. Mounting POSIX Message Queue File System... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. 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 udev Coldplug all Devices. [ 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. [ 13.693300] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 14.833885] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 14.926617] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 15.327442] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 16.007167] EDAC sbridge: Ver: 1.1.2 [ 17.365576] Key type dns_resolver registered [ 17.777899] NFS: Registering the id_resolver key type [ 17.780885] Key type id_resolver registered [ 17.783296] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ 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 ] Started dnf makecache --timer. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Restore /run/initramfs on shutdown... Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ 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 ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Hostname Service... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg246-client login: [ 88.781571] libcfs: loading out-of-tree module taints kernel. [ 88.823910] Key type ._llcrypt registered [ 88.826079] Key type .llcrypt registered [ 89.655840] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 89.679752] alg: No test for adler32 (adler32-zlib) [ 90.918421] Lustre: Lustre: Build Version: 2.17.53_33_g3f95abe [ 91.455707] LNet: Added LNI 192.168.202.46@tcp [8/256/0/180] [ 93.179821] Key type lgssc registered [ 94.892395] Lustre: Echo OBD driver; http://www.lustre.org/ [ 199.693893] Lustre: Mounted lustre-client [ 203.944921] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 217.529636] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing check_logdir /tmp/testlogs/ [ 222.434325] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing yml_node [ 225.251280] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 23s idle [ 225.726464] Lustre: DEBUG MARKER: Client: 2.17.53.33 [ 227.559650] Lustre: DEBUG MARKER: MDS: 2.17.53.33 [ 229.771254] Lustre: DEBUG MARKER: OSS: 2.17.53.33 [ 231.082764] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Mon Jun 1 11:17:06 EDT 2026 [ 246.621109] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 247.899690] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 12a 9 [ 249.736337] Lustre: DEBUG MARKER: === sanity-quota: start setup 11:17:24 (1780327044) === [ 252.722798] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing check_config_client /mnt/lustre [ 267.340462] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 276.694212] Lustre: DEBUG MARKER: === sanity-quota: finish setup 11:17:51 (1780327071) === [ 325.269142] hrtimer: interrupt took 5884153 ns [ 329.165231] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 11:18:44 (1780327124) [ 368.607359] Lustre: lustre-OST0001-osc-ffff931991ea8000: disconnect after 21s idle [ 368.624170] Lustre: Skipped 1 previous similar message [ 378.848691] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 23s idle [ 384.065783] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 11:19:39 (1780327179) [ 399.259290] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 405.119694] Lustre: DEBUG MARKER: Write... [ 406.953499] Lustre: DEBUG MARKER: Write out of block quota ... [ 424.928280] Lustre: lustre-OST0001-osc-ffff931991ea8000: disconnect after 22s idle [ 440.288162] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 21s idle [ 447.295817] Lustre: DEBUG MARKER: -------------------------------------- [ 448.519532] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 454.361108] Lustre: DEBUG MARKER: Write... [ 456.614906] Lustre: DEBUG MARKER: Write out of block quota ... [ 476.130549] Lustre: lustre-OST0001-osc-ffff931991ea8000: disconnect after 24s idle [ 500.661830] Lustre: DEBUG MARKER: -------------------------------------- [ 501.712669] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 503.960449] Lustre: DEBUG MARKER: Write... [ 506.323836] Lustre: DEBUG MARKER: Write out of block quota ... [ 522.207359] Lustre: lustre-OST0001-osc-ffff931991ea8000: disconnect after 23s idle [ 522.217150] Lustre: Skipped 1 previous similar message [ 563.167445] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 20s idle [ 563.170677] Lustre: Skipped 1 previous similar message [ 563.334672] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 11:22:38 (1780327358) [ 578.322540] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 592.375325] Lustre: DEBUG MARKER: Write... [ 594.542273] Lustre: DEBUG MARKER: Write out of block quota ... [ 629.731208] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 24s idle [ 629.736755] Lustre: Skipped 2 previous similar messages [ 633.888218] Lustre: DEBUG MARKER: -------------------------------------- [ 634.959449] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 640.422883] Lustre: DEBUG MARKER: Write... [ 642.349764] Lustre: DEBUG MARKER: Write out of block quota ... [ 682.736592] Lustre: DEBUG MARKER: -------------------------------------- [ 683.754066] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 685.869408] Lustre: DEBUG MARKER: Write... [ 687.537822] Lustre: DEBUG MARKER: Write out of block quota ... [ 747.221512] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 11:25:42 (1780327542) [ 759.813636] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 778.016818] Lustre: DEBUG MARKER: Write... [ 780.101922] Lustre: DEBUG MARKER: Write out of block quota ... [ 839.659226] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 20s idle [ 839.671611] Lustre: Skipped 6 previous similar messages [ 850.786501] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 11:27:26 (1780327646) [ 862.733873] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 878.970201] Lustre: DEBUG MARKER: Write... [ 880.448679] Lustre: DEBUG MARKER: Write out of block quota ... [ 948.209825] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 11:29:03 (1780327743) [ 959.609807] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 967.257762] Lustre: DEBUG MARKER: Write... [ 969.008437] Lustre: DEBUG MARKER: Write out of block quota ... [ 978.092550] Lustre: DEBUG MARKER: Write... [ 1024.250926] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 11:30:19 (1780327819) [ 1040.113551] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1056.028727] Lustre: DEBUG MARKER: Write... [ 1059.680185] Lustre: DEBUG MARKER: Write out of block quota ... [ 1105.887363] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 22s idle [ 1105.895607] Lustre: Skipped 9 previous similar messages [ 1116.651950] Lustre: DEBUG MARKER: Write... [ 1121.362650] Lustre: DEBUG MARKER: Write out of block quota ... [ 1178.469691] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 11:32:53 (1780327973) [ 1197.406793] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 1211.206605] Lustre: DEBUG MARKER: Write... [ 1223.481862] Lustre: DEBUG MARKER: Write out of block quota ... [ 1311.209650] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 11:35:06 (1780328106) [ 1312.901769] Lustre: DEBUG MARKER: SKIP: sanity-quota test_1h need >= 2.13.57 and ldiskfs for fallocate [ 1314.690554] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 11:35:09 (1780328109) [ 1331.111891] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1342.622125] Lustre: DEBUG MARKER: Write... [ 1345.264424] Lustre: DEBUG MARKER: Write out of block quota ... [ 1388.557812] Lustre: DEBUG MARKER: Write... [ 1391.474515] Lustre: DEBUG MARKER: Write out of block quota ... [ 1465.584362] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 11:37:39 (1780328259) [ 1491.412395] Lustre: DEBUG MARKER: -------------------------------------- [ 1492.781766] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 1827.808527] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 20s idle [ 1827.823992] Lustre: Skipped 10 previous similar messages [ 1866.889391] Lustre: DEBUG MARKER: == sanity-quota test 1k: LQA: Block hard limit (normal use and out of quota) ========================================================== 11:44:21 (1780328661) [ 1885.743507] Lustre: DEBUG MARKER: Write... [ 1889.508148] Lustre: DEBUG MARKER: Write out of block quota ... [ 1929.615505] Lustre: DEBUG MARKER: Write... [ 1932.948752] Lustre: DEBUG MARKER: Write out of block quota ... [ 1978.091784] Lustre: DEBUG MARKER: Write... [ 1982.134787] Lustre: DEBUG MARKER: Write out of block quota ... [ 2028.669918] Lustre: DEBUG MARKER: == sanity-quota test 1l: Async writes should not be rejected by quota with root_prj_enable ========================================================== 11:47:03 (1780328823) [ 2029.238139] Lustre: Mounted lustre-client [ 2082.582559] LustreError: 55265:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff931990e28800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 2082.620146] Lustre: Unmounted lustre-client [ 2083.771582] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 2084.897768] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 11:48:00 (1780328880) [ 2171.692570] Lustre: DEBUG MARKER: Write after timer goes off [ 2174.026664] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2302.950193] Lustre: DEBUG MARKER: Write after timer goes off [ 2304.473686] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2426.453560] Lustre: DEBUG MARKER: Write after timer goes off [ 2428.003378] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2472.928919] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 22s idle [ 2472.932736] Lustre: Skipped 21 previous similar messages [ 2511.790712] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 11:55:07 (1780329307) [ 2599.421895] Lustre: DEBUG MARKER: Write after timer goes off [ 2600.474200] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2723.621961] Lustre: DEBUG MARKER: Write after timer goes off [ 2724.952786] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2846.812796] Lustre: DEBUG MARKER: Write after timer goes off [ 2847.842351] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3001.345873] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 12:03:15 (1780329795) [ 3107.995743] Lustre: DEBUG MARKER: Write after timer goes off [ 3110.180992] Lustre: DEBUG MARKER: Write after cancel lru locks [ 3133.410391] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 20s idle [ 3133.416169] Lustre: Skipped 19 previous similar messages [ 3211.485231] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 3214.470893] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 12:06:48 (1780330008) [ 3234.282340] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 3410.889373] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 12:10:05 (1780330205) [ 3565.587419] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 12:12:40 (1780330360) [ 3599.847933] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection to lustre-OST0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3607.515804] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 3718.959760] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 12:15:14 (1780330514) [ 3748.327465] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection to lustre-OST0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3752.947697] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 3753.441915] Lustre: lustre-OST0001-osc-ffff931991ea8000: disconnect after 24s idle [ 3753.446259] Lustre: Skipped 12 previous similar messages [ 3867.755427] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 12:17:42 (1780330662) [ 3917.292427] Lustre: lustre-MDT0000-mdc-ffff931991ea8000: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3917.305110] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [ 3917.353714] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a614c16b4 to 0x225626a61554724 [ 3917.381438] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 3923.424949] Lustre: 2376:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780330703/real 1780330703] req@ffff931991715500 x1866808052400512/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780330719 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3928.608709] Lustre: 2376:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780330708/real 1780330708] req@ffff9319a04ca300 x1866808052401024/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780330724 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4087.509625] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 12:21:22 (1780330882) [ 4191.544717] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 12:23:05 (1780330985) [ 4193.174579] Lustre: DEBUG MARKER: SKIP: sanity-quota test_7e needs >= 2 MDTs [ 4195.275340] Lustre: DEBUG MARKER: == sanity-quota test 7f: Quota reintegration automatically ========================================================== 12:23:10 (1780330990) [ 4429.279479] Lustre: lustre-OST0000-osc-ffff931991ea8000: disconnect after 24s idle [ 4429.287275] Lustre: Skipped 12 previous similar messages [ 4453.353743] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 12:27:28 (1780331248) [ 4668.900934] Lustre: DEBUG MARKER: SKIP: sanity-quota test_9 skipping SLOW test 9 [ 4670.679943] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 12:31:05 (1780331465) [ 4741.297858] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 12:32:14 (1780331534) [ 4800.482377] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12a skipping SLOW test 12a [ 4802.378391] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 12:33:17 (1780331597) [ 4804.260292] Lustre: DEBUG MARKER: SKIP: sanity-quota test_12b needs >= 2 MDTs [ 4806.705591] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 12:33:21 (1780331601) [ 4885.255493] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 12:34:39 (1780331679) [ 4915.692045] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection to lustre-OST0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4928.362185] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 4928.370818] Lustre: Skipped 1 previous similar message [ 4982.654475] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 12:36:17 (1780331777) [ 5018.220203] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 12:36:52 (1780331812) [ 5037.807323] Lustre: setting import lustre-OST0000_UUID INACTIVE by administrator request [ 5047.780156] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection to lustre-OST0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5047.856556] LustreError: lustre-OST0000-osc-ffff931991ea8000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 5047.870519] Lustre: lustre-OST0000-osc-ffff931991ea8000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 5063.135374] Lustre: lustre-OST0001-osc-ffff931991ea8000: disconnect after 23s idle [ 5063.154905] Lustre: Skipped 9 previous similar messages [ 5080.462511] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 12:37:54 (1780331874) [ 5082.842236] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 5085.257576] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 12:37:59 (1780331879) [ 5477.207684] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 12:44:31 (1780332271) [ 5499.651091] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5507.503780] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 5513.895328] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5516.398582] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5540.320153] Lustre: 2378:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332320/real 1780332320] req@ffff931991627800 x1866808056431232/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780332336 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5540.332691] Lustre: lustre-MDT0000-mdc-ffff931991ea8000: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5540.339389] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [ 5540.350393] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a61554724 to 0x225626a61590e43 [ 5540.358314] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 5541.613322] Lustre: 5589:0:(mgc_request.c:1899:mgc_process_log()) MGC192.168.202.146@tcp: IR log lustre-cliir failed, not fatal: rc = -2 [ 5545.551748] Lustre: 2377:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332325/real 1780332325] req@ffff931991627b80 x1866808056431744/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780332341 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5545.598851] Lustre: 2377:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5550.576278] Lustre: 2376:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332330/real 1780332330] req@ffff93199178d180 x1866808056432384/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780332346 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5550.658539] LustreError: 2374:0:(client.c:3438:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff931990a4ca80 x1866808056419840/t8589941304(8589941304) o101->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 592/608 e 0 to 0 dl 1780332362 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 5550.811229] Lustre: lustre-MDT0000-mdc-ffff931991ea8000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 5554.847189] Lustre: 2378:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332335/real 1780332335] req@ffff9319888e1500 x1866808056432896/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780332351 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5562.699265] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5564.612725] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5581.137733] Lustre: DEBUG MARKER: (dd_pid=115470, time=9, timeout=600) [ 5634.417514] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5642.517634] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 5648.687899] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5650.989722] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5668.319325] Lustre: lustre-OST0001-osc-ffff931991ea8000: disconnect after 24s idle [ 5668.332901] Lustre: Skipped 12 previous similar messages [ 5674.463359] Lustre: 2377:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332454/real 1780332454] req@ffff931991624a80 x1866808056472960/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780332470 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5674.466301] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [ 5674.494958] Lustre: 2377:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5674.495528] Lustre: lustre-MDT0000-mdc-ffff931991ea8000: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5674.555821] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a61590e43 to 0x225626a61591796 [ 5674.563414] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 5676.268216] Lustre: 5589:0:(mgc_request.c:1899:mgc_process_log()) MGC192.168.202.146@tcp: IR log lustre-cliir failed, not fatal: rc = -2 [ 5684.703197] Lustre: 2376:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332464/real 1780332464] req@ffff93199178c700 x1866808056474112/t0(0) o400->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780332480 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5684.746347] Lustre: 2376:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5684.807309] LustreError: 2374:0:(client.c:3438:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff931990a4d180 x1866808056461824/t12884901904(12884901904) o101->lustre-MDT0000-mdc-ffff931991ea8000@192.168.202.146@tcp:12/10 lens 592/608 e 0 to 0 dl 1780332497 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 5684.929571] Lustre: lustre-MDT0000-mdc-ffff931991ea8000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [ 5696.839856] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5699.252605] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5714.802228] Lustre: DEBUG MARKER: (dd_pid=117900, time=8, timeout=600) [ 5786.402430] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 12:49:40 (1780332580) [ 5813.568347] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 5815.763766] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:2). [ 5822.799980] Lustre: DEBUG MARKER: Files for user (quota_usr), count=1: [ 5824.656568] Lustre: DEBUG MARKER: Block quota isn't 0 (u:quota_usr:2). [ 5861.581892] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 12:50:56 (1780332656) [ 5893.187492] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 5911.776166] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 5914.464862] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 5916.928225] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 5919.652188] Lustre: DEBUG MARKER: Set quota for 1 times [ 5923.842800] Lustre: DEBUG MARKER: Set quota for 2 times [ 5928.417671] Lustre: DEBUG MARKER: Set quota for 3 times [ 5933.075087] Lustre: DEBUG MARKER: Set quota for 4 times [ 5937.735109] Lustre: DEBUG MARKER: Set quota for 5 times [ 5942.208995] Lustre: DEBUG MARKER: Set quota for 6 times [ 5946.425577] Lustre: DEBUG MARKER: Set quota for 7 times [ 6013.969115] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 12:53:28 (1780332808) [ 6024.865331] LustreError: 127539:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff931991ea8000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6024.872629] LustreError: 127539:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 6024.890502] Lustre: Unmounted lustre-client [ 6127.394105] Lustre: Mounted lustre-client [ 6133.098977] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6159.105625] LustreError: 129599:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff931991685000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6159.120500] LustreError: 129599:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 6159.179874] Lustre: Unmounted lustre-client [ 6262.123425] Lustre: Mounted lustre-client [ 6268.330067] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6287.844329] Lustre: lustre-OST0000-osc-ffff931990447800: disconnect after 23s idle [ 6287.858857] Lustre: Skipped 10 previous similar messages [ 6288.450756] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 12:58:02 (1780333082) [ 6290.610557] Lustre: DEBUG MARKER: SKIP: sanity-quota test_23 Overwrite in place is not guaranteed to be space neutral on ZFS [ 6293.691873] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 12:58:07 (1780333087) [ 6363.674041] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 12:59:17 (1780333157) [ 6431.496521] Lustre: DEBUG MARKER: Write... [ 6435.558980] Lustre: DEBUG MARKER: Write out of block quota ... [ 6502.101930] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 13:01:36 (1780333296) [ 6511.656901] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 13:01:45 (1780333305) [ 6522.915594] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 13:01:57 (1780333317) [ 6533.994330] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 13:02:07 (1780333327) [ 6544.698663] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 13:02:18 (1780333338) [ 6621.318327] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 6802.178194] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 6897.120723] Lustre: lustre-OST0001-osc-ffff931990447800: disconnect after 23s idle [ 6897.141879] Lustre: Skipped 16 previous similar messages [ 7013.334873] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 13:10:07 (1780333807) [ 7089.935508] Lustre: DEBUG MARKER: Restart... [ 7092.211380] LustreError: 152223:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff931990447800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 7092.222726] LustreError: 152223:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 7092.299152] Lustre: Unmounted lustre-client [ 7180.216571] Lustre: Mounted lustre-client [ 7185.859695] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7259.493702] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 13:14:13 (1780334053) [ 7341.284954] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 13:15:35 (1780334135) [ 8936.418313] Lustre: lustre-OST0000-osc-ffff9319915ea800: disconnect after 23s idle [ 8936.422295] Lustre: Skipped 9 previous similar messages [ 9241.849694] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 13:47:16 (1780336036) [ 9256.652379] LustreError: 185553:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9319915ea800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 9256.664112] LustreError: 185553:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 9256.729089] Lustre: Unmounted lustre-client [ 9360.710970] Lustre: Mounted lustre-client [ 9366.289831] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 9386.464847] Lustre: lustre-OST0001-osc-ffff931990444800: disconnect after 23s idle [ 9386.471866] Lustre: Skipped 1 previous similar message [ 9405.433647] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 13:50:00 (1780336200) [ 9454.404508] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 13:50:48 (1780336248) [ 9504.987855] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 13:51:39 (1780336299) [ 9506.704245] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40c needs >= 2 MDTs [ 9508.454683] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 13:51:43 (1780336303) [ 9510.344848] Lustre: DEBUG MARKER: SKIP: sanity-quota test_40d needs >= 2 MDTs [ 9511.814146] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 13:51:46 (1780336306) [ 9601.505105] Lustre: lustre-OST0000-osc-ffff931990444800: disconnect after 24s idle [ 9601.511767] Lustre: Skipped 5 previous similar messages [ 9606.104360] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 13:53:20 (1780336400) [ 9663.973388] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 13:54:18 (1780336458) [ 9761.435339] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 13:55:55 (1780336555) [10093.025936] Lustre: lustre-OST0000-osc-ffff931990444800: disconnect after 23s idle [10093.033607] Lustre: Skipped 5 previous similar messages [10575.134915] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [10585.425171] Lustre: Unmounted lustre-client [10742.974561] Lustre: Mounted lustre-client [10748.648787] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10768.864225] Lustre: lustre-OST0000-osc-ffff931991003000: disconnect after 24s idle [10768.876278] Lustre: Skipped 3 previous similar messages [10792.666593] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 14:13:07 (1780337587) [10799.720690] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 14:13:14 (1780337594) [10847.084724] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 14:14:01 (1780337641) [10914.328328] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 14:15:09 (1780337709) [10946.483962] Lustre: DEBUG MARKER: rename directory return 255 [10995.990044] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 14:16:30 (1780337790) [11032.719593] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 14:17:07 (1780337827) [11081.466122] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 14:17:56 (1780337876) [11207.103928] LustreError: 218098:0:(llite_lib.c:2036:ll_md_setattr()) md_setattr fails: rc = -122 [11248.605473] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 14:20:43 (1780338043) [11295.490150] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 14:21:29 (1780338089) [11345.921949] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 14:22:20 (1780338140) [11428.712082] LustreError: 223692:0:(file.c:252:ll_close_inode_openhandle()) lustre-clilmv-ffff931991003000: inode [0x200000401:0xad:0x0] mdc close failed: rc = -22 [11449.823634] Lustre: lustre-OST0000-osc-ffff931991003000: disconnect after 22s idle [11449.834579] Lustre: Skipped 11 previous similar messages [11517.185858] LustreError: 225030:0:(file.c:252:ll_close_inode_openhandle()) lustre-clilmv-ffff931991003000: inode [0x200000401:0xad:0x0] mdc close failed: rc = -22 [11517.195578] LustreError: 225030:0:(file.c:252:ll_close_inode_openhandle()) Skipped 1 previous similar message [11553.401877] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 14:25:48 (1780338348) [11555.580478] Lustre: DEBUG MARKER: SKIP: sanity-quota test_59 ldiskfs only test [11557.699344] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 14:25:52 (1780338352) [11621.563295] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [11624.057850] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 14:26:58 (1780338418) [11657.329268] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [11659.518203] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 14:27:33 (1780338453) [11712.740126] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [11715.127323] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 14:28:29 (1780338509) [11768.434836] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 14:29:23 (1780338563) [11770.285329] Lustre: DEBUG MARKER: SKIP: sanity-quota test_67 ZFS grants some block space together with inode [11772.827487] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 14:29:27 (1780338567) [11851.781585] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 14:30:45 (1780338645) [11879.901197] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [11881.762802] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [12064.223297] Lustre: lustre-OST0000-osc-ffff931991003000: disconnect after 20s idle [12064.239730] Lustre: Skipped 8 previous similar messages [12071.976756] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 14:34:26 (1780338866) [12130.072032] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 14:35:24 (1780338924) [12171.218940] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 14:36:05 (1780338965) [12172.802592] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71a ZFS grants some block space together with inode [12175.300755] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 14:36:09 (1780338969) [12177.114898] Lustre: DEBUG MARKER: SKIP: sanity-quota test_71b ZFS grants some block space together with inode [12179.044891] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 14:36:13 (1780338973) [12199.627883] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [12217.615713] Lustre: DEBUG MARKER: Write... [12221.330580] Lustre: DEBUG MARKER: Write out of block quota ... [12287.388272] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 14:38:01 (1780339081) [12321.574555] Lustre: DEBUG MARKER: set to use default quota [12323.604884] Lustre: DEBUG MARKER: set default quota [12325.819635] Lustre: DEBUG MARKER: get default quota [12333.845688] Lustre: DEBUG MARKER: Test not out of quota [12339.525262] Lustre: DEBUG MARKER: Test out of quota [12354.946585] Lustre: DEBUG MARKER: Increase default quota [12388.614594] Lustre: DEBUG MARKER: Set quota to override default quota [12405.014755] Lustre: DEBUG MARKER: Set to use default quota again [12431.753681] Lustre: DEBUG MARKER: Cleanup [12521.346665] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 14:41:55 (1780339315) [12549.812423] Lustre: DEBUG MARKER: set default quota for qpool1 [12552.020256] Lustre: DEBUG MARKER: Write from user that hasn't lqe [12605.556632] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 14:43:20 (1780339400) [12678.632430] Lustre: lustre-OST0000-osc-ffff931991003000: disconnect after 24s idle [12678.649192] Lustre: Skipped 8 previous similar messages [12704.686950] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 14:44:59 (1780339499) [12798.104801] Lustre: DEBUG MARKER: Write... [12803.054070] Lustre: DEBUG MARKER: Write out of block quota ... [12937.699805] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 14:48:52 (1780339732) [12988.811803] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 14:49:43 (1780339783) [12989.411607] Lustre: Mounted lustre-client read-only [12989.663237] LustreError: 257155:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9319833a2800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [12989.674185] LustreError: 257155:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [12989.729386] Lustre: Unmounted lustre-client [12997.299639] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 14:49:51 (1780339791) [12999.334927] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78A need >= 2.13.57 and ldiskfs for fallocate [13001.632079] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 14:49:55 (1780339795) [13004.294104] Lustre: DEBUG MARKER: SKIP: sanity-quota test_78a need >= 2.13.57 and ldiskfs for fallocate [13006.629743] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 14:50:00 (1780339800) [13030.499700] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 14:50:25 (1780339825) [13032.534819] Lustre: DEBUG MARKER: SKIP: sanity-quota test_80 ZFS grants some block space together with inode [13034.742941] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 14:50:29 (1780339829) [13054.920988] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [13066.231793] Lustre: lustre-MDT0000-mdc-ffff931991003000: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [13086.701532] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [13086.753212] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a617a16d6 to 0x225626a617b40b8 [13086.791944] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [13096.108046] LustreError: lustre-MDT0000-mdc-ffff931991003000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13096.120869] Lustre: lustre-MDT0000-mdc-ffff931991003000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [13132.146361] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 14:52:06 (1780339926) [13168.473586] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 14:52:43 (1780339963) [13206.313451] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 14:53:21 (1780340001) [13342.179269] Lustre: lustre-OST0001-osc-ffff931991003000: disconnect after 22s idle [13342.185764] Lustre: Skipped 16 previous similar messages [13405.884665] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 14:56:40 (1780340200) [13510.915344] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 14:58:25 (1780340305) [14129.157987] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 15:08:43 (1780340923) [14202.335583] Lustre: lustre-OST0000-osc-ffff931991003000: disconnect after 21s idle [14202.345353] Lustre: Skipped 3 previous similar messages [14253.548237] Lustre: lustre-MDT0000-mdc-ffff931991003000: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [14268.910220] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [14268.937739] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a617b40b8 to 0x225626a618b6cba [14268.960451] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [14273.131224] LustreError: lustre-MDT0000-mdc-ffff931991003000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14273.173172] Lustre: lustre-MDT0000-mdc-ffff931991003000: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [14303.601118] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 15:11:37 (1780341097) [14305.485809] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [14308.424517] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 15:11:42 (1780341102) [14323.552391] LustreError: 273030:0:(mdc_request.c:2182:mdc_quotactl()) lustre-MDT0000-mdc-ffff931991003000: ptlrpc_queue_wait failed: rc = -1 [14340.171091] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 15:12:14 (1780341134) [14366.768672] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 15:12:41 (1780341161) [14383.088372] Lustre: Mounted lustre-client [14393.722706] LustreError: 275595:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff931991687000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [14393.739059] LustreError: 275595:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [14393.774471] Lustre: Unmounted lustre-client [14396.209791] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 15:13:10 (1780341190) [14399.404332] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [14399.420423] Lustre: Skipped 2 previous similar messages [14409.760564] Lustre: Unmounted lustre-client [14508.656412] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [14531.185597] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [14554.195572] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid [14554.898392] Lustre: Mounted lustre-client [14565.351292] Lustre: lustre-MDT0000-mdc-ffff931987bf6800: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [14580.710851] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [14580.728663] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a618b7175 to 0x225626a618b7485 [14580.742522] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [14584.919090] LustreError: lustre-MDT0000-mdc-ffff931987bf6800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14584.941122] Lustre: lustre-MDT0000-mdc-ffff931987bf6800: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [14587.558880] Lustre: DEBUG MARKER: oleg246-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [14589.227317] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [14597.063751] LustreError: 279360:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff931987bf6800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [14597.075561] LustreError: 279360:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [14597.113055] Lustre: Unmounted lustre-client [14727.732739] Lustre: Mounted lustre-client [14731.790668] Lustre: DEBUG MARKER: Using TIMEOUT=20 [14741.485806] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 15:18:56 (1780341536) [14756.126065] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 15:19:11 (1780341551) [14830.055865] Lustre: lustre-OST0000-osc-ffff9319833a4800: disconnect after 21s idle [14830.060537] Lustre: Skipped 9 previous similar messages [14842.868304] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 15:20:37 (1780341637) [14881.255500] Lustre: lustre-MDT0000-mdc-ffff9319833a4800: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [14896.615454] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [14896.642533] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a618b786e to 0x225626a618b7ee9 [14896.662363] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [14900.851587] LustreError: lustre-MDT0000-mdc-ffff9319833a4800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14906.855985] Lustre: lustre-MDT0000-mdc-ffff9319833a4800: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [14922.211716] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [14922.228460] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a618b7ee9 to 0x225626a618b81b3 [14922.237223] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [14922.243308] Lustre: Skipped 1 previous similar message [14937.617229] LustreError: lustre-MDT0000-mdc-ffff9319833a4800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14939.147703] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 15:22:14 (1780341734) [14962.286199] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 15:22:37 (1780341757) [15004.189394] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 15:23:19 (1780341799) [15005.760362] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 the test in only needed to run on LDiskFS [15007.248343] Lustre: DEBUG MARKER: == sanity-quota test 97a: LQA control commands =========== 15:23:22 (1780341802) [15027.815407] Lustre: DEBUG MARKER: == sanity-quota test 97b: Check LQA internals ============ 15:23:42 (1780341822) [15054.949632] Lustre: DEBUG MARKER: adding 50 LQA ranges took 1s [15059.367956] Lustre: DEBUG MARKER: Removing 50 LQA ranges took 1s [15066.536559] Lustre: DEBUG MARKER: == sanity-quota test 97c: LQA lfs quota commands and MDS restart consistency ========================================================== 15:24:21 (1780341861) [15075.813764] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [15075.828479] Lustre: lustre-MDT0000-mdc-ffff9319833a4800: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [15075.842653] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a618b81b3 to 0x225626a618b8691 [15075.862563] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [15075.869064] Lustre: Skipped 1 previous similar message [15086.047115] Lustre: 2377:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780341866/real 1780341866] req@ffff931984521880 x1866808096285824/t0(0) o400->lustre-MDT0000-mdc-ffff9319833a4800@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780341882 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [15086.072310] Lustre: 2377:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [15089.596648] Lustre: DEBUG MARKER: == sanity-quota test 97d: LQA disk persistence using standard commands ========================================================== 15:24:44 (1780341884) [15116.773889] Lustre: lustre-MDT0000-mdc-ffff9319833a4800: Connection to lustre-MDT0000 (at 192.168.202.146@tcp) was lost; in progress operations using this service will wait for recovery to complete [15116.788437] LustreError: MGC192.168.202.146@tcp: Connection to MGS (at 192.168.202.146@tcp) was lost; in progress operations using this service will fail [15116.813123] Lustre: Evicted from MGS (at 192.168.202.146@tcp) after server handle changed from 0x225626a618b8691 to 0x225626a618b8a18 [15116.823771] Lustre: MGC192.168.202.146@tcp: Connection restored to 192.168.202.146@tcp (at 192.168.202.146@tcp) [15116.830121] Lustre: Skipped 1 previous similar message [15127.008186] Lustre: 2378:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780341907/real 1780341907] req@ffff931990be5c00 x1866808096291200/t0(0) o400->lustre-MDT0000-mdc-ffff9319833a4800@192.168.202.146@tcp:12/10 lens 224/224 e 0 to 1 dl 1780341923 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [15156.841684] Lustre: DEBUG MARKER: == sanity-quota test 98: Verify MDT retry on -EDQUOT during mkdir ========================================================== 15:25:52 (1780341952) [15158.055528] Lustre: DEBUG MARKER: SKIP: sanity-quota test_98 needs >= 2 MDTs [15161.708437] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 14930 sec ======== 15:25:57 (1780341957) [15162.965763] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 15:25:58 (1780341958) === [15165.624483] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 15:26:00 (1780341960) === [15166.660196] LustreError: 296361:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9319833a4800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [15166.665283] LustreError: 296361:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [15166.685812] Lustre: Unmounted lustre-client [15200.162927] Key type lgssc unregistered [15200.360323] LNet: 296843:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [15200.364521] LNetError: 296843:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [15200.375216] LNet: Removed LNI 192.168.202.46@tcp [15200.925187] Key type .llcrypt unregistered [15200.927488] Key type ._llcrypt unregistered