[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 3.0.0 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-2.fc40 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 425034848 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f53f0-0x000f53ff] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5200 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1D87 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1C23 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001BE3 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1C97 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1D27 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1D5F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1c23-0xbffe1c96] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1c22] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1c97-0xbffe1d26] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1d27-0xbffe1d5e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1d5f-0xbffe1d86] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001012] APIC: Switch to symmetric I/O mode setup [ 0.003230] x2apic enabled [ 0.004006] Switched APIC routing to physical x2apic. [ 0.005006] kvm-guest: setup PV IPIs [ 0.008000] ..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.008019] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009006] pid_max: default: 32768 minimum: 301 [ 0.010143] LSM: Security Framework initializing [ 0.011033] Yama: becoming mindful. [ 0.012022] SELinux: Initializing. [ 0.013047] *** VALIDATE selinux *** [ 0.022737] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.028242] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029121] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030082] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031077] *** VALIDATE tmpfs *** [ 0.033386] *** VALIDATE proc *** [ 0.034186] *** VALIDATE cgroup *** [ 0.035005] *** VALIDATE cgroup2 *** [ 0.037107] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038109] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039004] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040019] Spectre V2 : User space: Vulnerable [ 0.041004] Speculative Store Bypass: Vulnerable [ 0.043883] debug: unmapping init [mem 0xffffffff89e59000-0xffffffff89e60fff] [ 0.045171] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046742] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.047025] ... version: 2 [ 0.048007] ... bit width: 48 [ 0.049006] ... generic registers: 4 [ 0.050008] ... value mask: 0000ffffffffffff [ 0.051008] ... max period: 00007fffffffffff [ 0.052006] ... fixed-purpose events: 3 [ 0.053007] ... event mask: 000000070000000f [ 0.054263] rcu: Hierarchical SRCU implementation. [ 0.056291] smp: Bringing up secondary CPUs ... [ 0.057484] x86: Booting SMP configuration: [ 0.058016] .... node #0, CPUs: #1 #2 #3 [ 0.060749] smp: Brought up 1 node, 4 CPUs [ 0.062008] smpboot: Max logical packages: 1 [ 0.063010] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.252192] node 0 deferred pages initialised in 188ms [ 0.255014] devtmpfs: initialized [ 0.256203] x86/mm: Memory block size: 128MB [ 0.258775] gcov: version magic: 0x41383552 [ 0.260080] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.261067] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.262221] pinctrl core: initialized pinctrl subsystem [ 0.263166] [ 0.263711] ************************************************************* [ 0.264010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.265010] ** ** [ 0.266010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.267011] ** ** [ 0.268013] ** This means that this kernel is built to expose internal ** [ 0.269012] ** IOMMU data structures, which may compromise security on ** [ 0.270023] ** your system. ** [ 0.271006] ** ** [ 0.272008] ** If you see this message and you are not debugging the ** [ 0.273013] ** kernel, report this immediately to your vendor! ** [ 0.274008] ** ** [ 0.275006] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.276009] ************************************************************* [ 0.277728] NET: Registered protocol family 16 [ 0.278377] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.279041] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.280058] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.281419] cpuidle: using governor menu [ 0.283256] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.285423] PCI: Using configuration type 1 for base access [ 0.287119] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.293077] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.294016] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.295149] cryptd: max_cpu_qlen set to 1000 [ 0.296193] ACPI: Added _OSI(Module Device) [ 0.297020] ACPI: Added _OSI(Processor Device) [ 0.297996] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.299007] ACPI: Added _OSI(Processor Aggregator Device) [ 0.302285] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.304370] ACPI: Interpreter enabled [ 0.305035] ACPI: PM: (supports S0 S3 S4 S5) [ 0.306007] ACPI: Using IOAPIC for interrupt routing [ 0.307056] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.308305] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.315584] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.316024] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.317011] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.318051] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.319951] acpiphp: Slot [2] registered [ 0.320061] acpiphp: Slot [5] registered [ 0.320914] acpiphp: Slot [6] registered [ 0.321061] acpiphp: Slot [7] registered [ 0.321919] acpiphp: Slot [8] registered [ 0.322047] acpiphp: Slot [9] registered [ 0.322944] acpiphp: Slot [10] registered [ 0.323048] acpiphp: Slot [3] registered [ 0.323922] acpiphp: Slot [4] registered [ 0.324046] acpiphp: Slot [11] registered [ 0.325068] acpiphp: Slot [12] registered [ 0.326084] acpiphp: Slot [13] registered [ 0.327068] acpiphp: Slot [14] registered [ 0.328068] acpiphp: Slot [15] registered [ 0.329073] acpiphp: Slot [16] registered [ 0.330089] acpiphp: Slot [17] registered [ 0.331050] acpiphp: Slot [18] registered [ 0.331951] acpiphp: Slot [19] registered [ 0.332047] acpiphp: Slot [20] registered [ 0.332884] acpiphp: Slot [21] registered [ 0.333060] acpiphp: Slot [22] registered [ 0.333945] acpiphp: Slot [23] registered [ 0.334052] acpiphp: Slot [24] registered [ 0.335099] acpiphp: Slot [25] registered [ 0.336104] acpiphp: Slot [26] registered [ 0.337073] acpiphp: Slot [27] registered [ 0.338075] acpiphp: Slot [28] registered [ 0.339075] acpiphp: Slot [29] registered [ 0.340067] acpiphp: Slot [30] registered [ 0.341070] acpiphp: Slot [31] registered [ 0.342048] PCI host bridge to bus 0000:00 [ 0.343014] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.344016] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.345018] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.346016] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.347022] pci_bus 0000:00: root bus resource [mem 0x380000000000-0x38007fffffff window] [ 0.348019] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.349161] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.350983] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.351913] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.356013] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.358460] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.359010] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.360008] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.361014] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.362552] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.363784] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.364034] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.365737] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.367012] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.374888] pci 0000:00:02.0: reg 0x20: [mem 0x380000000000-0x380000003fff 64bit pref] [ 0.376011] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.380630] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.383017] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.386053] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.394020] pci 0000:00:05.0: reg 0x20: [mem 0x380000004000-0x380000007fff 64bit pref] [ 0.400341] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.403014] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.406016] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.414026] pci 0000:00:06.0: reg 0x20: [mem 0x380000008000-0x38000000bfff 64bit pref] [ 0.420420] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.423013] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.426013] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.433033] pci 0000:00:07.0: reg 0x20: [mem 0x38000000c000-0x38000000ffff 64bit pref] [ 0.439124] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.442025] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.445020] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.453022] pci 0000:00:08.0: reg 0x20: [mem 0x380000010000-0x380000013fff 64bit pref] [ 0.458966] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.461014] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.464038] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.471016] pci 0000:00:09.0: reg 0x20: [mem 0x380000014000-0x380000017fff 64bit pref] [ 0.477679] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.480024] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.484016] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.491019] pci 0000:00:0a.0: reg 0x20: [mem 0x380000018000-0x38000001bfff 64bit pref] [ 0.498060] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.499314] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.500281] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.501302] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.502183] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.506046] iommu: Default domain type: Passthrough [ 0.507710] SCSI subsystem initialized [ 0.509127] ACPI: bus type USB registered [ 0.510136] usbcore: registered new interface driver usbfs [ 0.512092] usbcore: registered new interface driver hub [ 0.513080] usbcore: registered new device driver usb [ 0.515210] pps_core: LinuxPPS API ver. 1 registered [ 0.516008] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.519073] PTP clock support registered [ 0.520396] EDAC MC: Ver: 3.0.0 [ 0.522217] PCI: Using ACPI for IRQ routing [ 0.525027] NetLabel: Initializing [ 0.526013] NetLabel: domain hash size = 128 [ 0.527007] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.529112] NetLabel: unlabeled traffic allowed by default [ 0.531322] vgaarb: loaded [ 0.534436] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.536011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.547206] clocksource: Switched to clocksource kvm-clock [ 0.654920] VFS: Disk quotas dquot_6.6.0 [ 0.656011] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.658373] *** VALIDATE ramfs *** [ 0.659544] *** VALIDATE hugetlbfs *** [ 0.660990] pnp: PnP ACPI init [ 0.663326] pnp: PnP ACPI: found 6 devices [ 0.683594] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.687388] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.689395] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.690747] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.692315] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.694193] pci_bus 0000:00: resource 8 [mem 0x380000000000-0x38007fffffff window] [ 0.696513] NET: Registered protocol family 2 [ 0.698669] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.704278] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.708276] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.713738] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.716569] TCP: Hash tables configured (established 65536 bind 65536) [ 0.719252] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.722063] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.726017] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.728737] NET: Registered protocol family 1 [ 0.731647] RPC: Registered named UNIX socket transport module. [ 0.733636] RPC: Registered udp transport module. [ 0.734844] RPC: Registered tcp transport module. [ 0.736143] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.737793] NET: Registered protocol family 44 [ 0.738692] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.740360] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.742161] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.743885] PCI: CLS 0 bytes, default 64 [ 0.745809] Unpacking initramfs... [ 2.352586] debug: unmapping init [mem 0xffff9981bcc54000-0xffff9981bffbffff] [ 2.359572] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.361579] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.365342] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.917177] Initialise system trusted keyrings [ 2.919011] Key type blacklist registered [ 2.922211] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.931823] zbud: loaded [ 2.936568] *** VALIDATE nfs *** [ 2.938033] *** VALIDATE nfs4 *** [ 2.939639] pstore: using deflate compression [ 2.945574] Platform Keyring initialized [ 3.093459] NET: Registered protocol family 38 [ 3.095203] Key type asymmetric registered [ 3.096326] Asymmetric key parser 'x509' registered [ 3.097808] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.101198] io scheduler mq-deadline registered [ 3.103173] io scheduler kyber registered [ 3.105162] io scheduler bfq registered [ 3.107620] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.115957] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.118282] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.122637] ACPI: Power Button [PWRF] [ 3.234735] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.331483] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.599295] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.717938] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.976365] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 4.011668] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 4.045887] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 4.050760] Non-volatile memory driver v1.3 [ 4.055334] Linux agpgart interface v0.103 [ 4.098707] virtio_blk virtio1: [vda] 133256 512-byte logical blocks (68.2 MB/65.1 MiB) [ 4.102276] vda: detected capacity change from 0 to 68227072 [ 4.123172] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 4.129013] vdb: detected capacity change from 0 to 1073741824 [ 4.144695] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.147069] vdc: detected capacity change from 0 to 2621440000 [ 4.167228] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.173117] vdd: detected capacity change from 0 to 2621440000 [ 4.199576] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.204833] vde: detected capacity change from 0 to 4294967296 [ 4.229568] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.233066] vdf: detected capacity change from 0 to 4294967296 [ 4.255258] libphy: Fixed MDIO Bus: probed [ 4.267582] usbcore: registered new interface driver usbserial_generic [ 4.270617] usbserial: USB Serial support registered for generic [ 4.276358] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 4.285472] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 4.294472] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 4.300034] mousedev: PS/2 mouse device common for all mice [ 4.302353] rtc_cmos 00:05: RTC can wake from S4 [ 4.307297] rtc_cmos 00:05: registered as rtc0 [ 4.309389] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 4.313101] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 4.329521] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 4.330835] intel_pstate: CPU model not supported [ 4.337697] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 4.341786] hid: raw HID events driver (C) Jiri Kosina [ 4.344625] usbcore: registered new interface driver usbhid [ 4.350215] usbhid: USB HID core driver [ 4.352198] drop_monitor: Initializing network drop monitor service [ 4.367070] Initializing XFRM netlink socket [ 4.369399] NET: Registered protocol family 10 [ 4.372589] Segment Routing with IPv6 [ 4.374366] NET: Registered protocol family 17 [ 4.376546] mpls_gso: MPLS GSO support [ 4.381898] RAS: Correctable Errors collector initialized. [ 4.383952] AVX version of gcm_enc/dec engaged. [ 4.385748] AES CTR mode by8 optimization enabled [ 4.510271] sched_clock: Marking stable (4510021445, 0)->(5364244689, -854223244) [ 4.518179] registered taskstats version 1 [ 4.525915] Loading compiled-in X.509 certificates [ 4.528299] zswap: loaded using pool lzo/zbud [ 4.587697] Key type big_key registered [ 4.608634] Key type encrypted registered [ 4.611763] ima: No TPM chip found, activating TPM-bypass! [ 4.614503] ima: Allocated hash algorithm: sha1 [ 4.618754] ima: No architecture policies found [ 4.620804] evm: Initialising EVM extended attributes: [ 4.622927] evm: security.selinux [ 4.624411] evm: security.ima [ 4.625755] evm: security.capability [ 4.628502] evm: HMAC attrs: 0x1 [ 4.632322] rtc_cmos 00:05: setting system clock to 2025-07-14 16:15:00 UTC (1752509700) [ 4.643626] debug: unmapping init [mem 0xffffffff8ae03000-0xffffffff8affffff] [ 4.647200] debug: unmapping init [mem 0xffffffff89b82000-0xffffffff89e58fff] [ 4.659101] Write protecting the kernel read-only data: 28672k [ 4.662970] debug: unmapping init [mem 0xffffffff88203000-0xffffffff883fffff] [ 4.666051] debug: unmapping init [mem 0xffffffff88b14000-0xffffffff88bfffff] [ 4.714839] 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) [ 4.725740] systemd[1]: Detected virtualization kvm. [ 4.728256] systemd[1]: Detected architecture x86-64. [ 4.730570] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.758462] systemd[1]: No hostname configured. [ 4.760707] systemd[1]: Set hostname to . [ 4.764069] random: systemd: uninitialized urandom read (16 bytes read) [ 4.767715] systemd[1]: Initializing machine ID from random generator. [ 5.007778] random: systemd: uninitialized urandom read (16 bytes read) [ 5.013154] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 5.022724] random: systemd: uninitialized urandom read (16 bytes read) [ 5.026231] systemd[1]: Reached target Paths. [ OK ] Reached target Paths. [ 5.033085] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Timers. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... Starting Create Volatile Files and Directories... [ OK ] Reached target Slices. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Memstrack Anylazing Service. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Swap. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ 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. [ 5.871034] hrtimer: interrupt took 15090068 ns [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 6.619638] device-mapper: uevent: version 1.0.3 [ 6.621980] 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 ] Started udev Coldplug all Devices. [ OK ] Mounted Kernel Configuration File System. [ OK ] Reached target System Initialization. [ OK [0[ 7.792899] virtio_net virtio0 ens2: renamed from eth0 m] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 7.917653] random: fast init done Starting dracut initqueue hook... [ 8.355449] scsi host0: ata_piix [ 8.471434] scsi host1: ata_piix [ 8.472821] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 8.479502] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 13.134916] random: crng init done [ 13.140218] random: 7 urandom warning(s) missed due to ratelimiting [ 13.310651] dracut-initqueue[576]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 13.956650] 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 dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Timers. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ 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. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local File Systems. [ 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 Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 15.266471] printk: systemd: 26 output lines suppressed due to ratelimiting [ 15.930369] SELinux: Disabled at runtime. [ 16.011356] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 16.021876] systemd[1]: Detected virtualization kvm. [ 16.024574] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 16.897478] systemd[1]: initrd-switch-root.service: Succeeded. [ 16.901899] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 16.914780] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 16.921988] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 16.930946] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 16.952860] systemd[1]: Starting Journal Service... Starting Journal Service... [ 16.969093] systemd[1]: Activating swap /dev/disk/by-label/SWAP... Activating swap /dev/disk/by-label/SWAP... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice system-getty.slice. [ OK ] Created slice User and Session Slice. Mounting Huge Pages File System... [ OK ] Listening on udev Kernel Socket. [[ 17.012878] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS  OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on Process Core Dump Socket. Starting Apply Kernel Variables... Mounting Kernel Debug File System... [ OK ] Stopped target Initrd File Systems. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Reached target Slices. [ OK ] Created slice system-serial\x2dgetty.slice. Mounting POSIX Message Queue File System... [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 17.707976] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 18.303150] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 18.306890] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 18.752926] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 18.805328] EDAC sbridge: Ver: 1.1.2 [ 20.977281] Key type dns_resolver registered [ 21.412198] NFS: Registering the id_resolver key type [ 21.414096] Key type id_resolver registered [ 21.416047] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Restore /run/initramfs on shutdown... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting System Logging Service... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg126-server login: [ 44.948655] libcfs: loading out-of-tree module taints kernel. [ 44.957297] Key type ._llcrypt registered [ 44.958286] Key type .llcrypt registered [ 44.992464] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_hostid [ 52.305856] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 52.945756] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 52.955769] alg: No test for adler32 (adler32-zlib) [ 53.933688] Lustre: Lustre: Build Version: 2.16.57_2_ge787a7d [ 54.254112] LNet: Added LNI 192.168.201.126@tcp [8/256/0/180] [ 54.255893] LNet: Accept secure, port 988 [ 55.864170] Key type lgssc registered [ 56.406734] Lustre: Echo OBD driver; http://www.lustre.org/ [ 62.855159] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 64.063609] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 67.641390] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 70.163892] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 72.765553] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 78.254535] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 82.765726] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 82.789866] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 82.801411] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 83.896784] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 83.910666] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 83.955251] Lustre: lustre-MDT0000: new disk, initializing [ 83.986448] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 83.994258] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 85.327327] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 90.581612] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 90.609864] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 90.641071] Lustre: 6437:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 90.656034] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 90.658553] Lustre: Skipped 1 previous similar message [ 90.697480] Lustre: lustre-MDT0001: new disk, initializing [ 90.717883] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 90.726024] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 90.729161] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 92.069772] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 94.334808] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 97.591234] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 97.617503] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 97.709265] Lustre: lustre-OST0000: new disk, initializing [ 97.711358] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 97.728731] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 99.585769] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 99.630768] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 99.633466] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 99.658056] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 105.331196] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 105.360136] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 105.391982] Lustre: lustre-OST0001: new disk, initializing [ 105.393787] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 105.409811] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 107.292888] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 108.588660] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 108.591916] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 108.602218] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 113.277843] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 118.946478] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 125.856536] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing check_logdir /tmp/testlogs/ [ 127.348510] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing yml_node [ 129.014367] Lustre: DEBUG MARKER: Client: 2.16.57.2 [ 129.892106] Lustre: DEBUG MARKER: MDS: 2.16.57.2 [ 130.845200] Lustre: DEBUG MARKER: OSS: 2.16.57.2 [ 131.495796] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Mon Jul 14 12:17:07 EDT 2025 [ 137.235420] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 137.722209] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 [ 138.709562] Lustre: DEBUG MARKER: === sanity-quota: start setup 12:17:14 (1752509834) === [ 139.795911] Lustre: DEBUG MARKER: oleg126-client.virtnet: executing check_config_client /mnt/lustre [ 145.990395] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 147.106683] Lustre: 13170:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 148.182332] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 149.907371] Lustre: DEBUG MARKER: === sanity-quota: finish setup 12:17:25 (1752509845) === [ 164.041035] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 12:17:39 (1752509859) [ 184.397156] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 12:18:00 (1752509880) [ 188.143044] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 189.964046] Lustre: DEBUG MARKER: Write... [ 190.716634] Lustre: DEBUG MARKER: Write out of block quota ... [ 210.321120] Lustre: DEBUG MARKER: -------------------------------------- [ 210.854953] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 212.522534] Lustre: DEBUG MARKER: Write... [ 213.197690] Lustre: DEBUG MARKER: Write out of block quota ... [ 232.484961] Lustre: DEBUG MARKER: -------------------------------------- [ 232.983815] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 233.869729] Lustre: DEBUG MARKER: Write... [ 234.599731] Lustre: DEBUG MARKER: Write out of block quota ... [ 260.051186] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 12:19:15 (1752509955) [ 263.872313] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 270.195308] Lustre: DEBUG MARKER: Write... [ 270.918446] Lustre: DEBUG MARKER: Write out of block quota ... [ 289.494821] Lustre: DEBUG MARKER: -------------------------------------- [ 290.010315] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 291.809860] Lustre: DEBUG MARKER: Write... [ 292.584633] Lustre: DEBUG MARKER: Write out of block quota ... [ 313.426319] Lustre: DEBUG MARKER: -------------------------------------- [ 313.918417] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 314.809388] Lustre: DEBUG MARKER: Write... [ 315.513760] Lustre: DEBUG MARKER: Write out of block quota ... [ 346.571603] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 12:20:42 (1752510042) [ 350.652326] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 364.378350] Lustre: DEBUG MARKER: Write... [ 365.378451] Lustre: DEBUG MARKER: Write out of block quota ... [ 405.444159] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 12:21:41 (1752510101) [ 409.173703] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 422.346577] Lustre: DEBUG MARKER: Write... [ 423.063483] Lustre: DEBUG MARKER: Write out of block quota ... [ 463.508608] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 12:22:39 (1752510159) [ 466.981304] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 472.734493] Lustre: DEBUG MARKER: Write... [ 473.512830] Lustre: DEBUG MARKER: Write out of block quota ... [ 480.416198] Lustre: DEBUG MARKER: Write... [ 501.101721] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 12:23:16 (1752510196) [ 504.548837] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 510.256117] Lustre: DEBUG MARKER: Write... [ 511.018353] Lustre: DEBUG MARKER: Write out of block quota ... [ 529.225566] Lustre: DEBUG MARKER: Write... [ 529.948288] Lustre: DEBUG MARKER: Write out of block quota ... [ 558.633742] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 12:24:14 (1752510254) [ 562.544508] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 568.166585] Lustre: 10043:0:(osd_handler.c:2067:osd_trans_start()) lustre-MDT0000: credits 6345 > trans_max 3200 [ 568.169360] Lustre: 10043:0:(osd_handler.c:1966:osd_trans_dump_creds()) create: 4/16/0, destroy: 0/0/0 [ 568.171649] Lustre: 10043:0:(osd_handler.c:1973:osd_trans_dump_creds()) attr_set: 401/401/0, xattr_set: 602/5615/0 [ 568.174704] Lustre: 10043:0:(osd_handler.c:1983:osd_trans_dump_creds()) write: 20/109/0, punch: 0/0/0, quota 8/136/0 [ 568.176857] Lustre: 10043:0:(osd_handler.c:1990:osd_trans_dump_creds()) insert: 4/68/0, delete: 0/0/0 [ 568.178619] Lustre: 10043:0:(osd_handler.c:1997:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 568.180535] CPU: 0 PID: 10043 Comm: mdt00_004 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [ 568.183144] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-2.fc40 04/01/2014 [ 568.185390] Call Trace: [ 568.186020] ? dump_stack+0xbb/0x10e [ 568.186715] ? osd_trans_start+0x8db/0x9d0 [osd_ldiskfs] [ 568.187758] ? top_trans_start+0x599/0xd80 [ptlrpc] [ 568.188966] ? lod_ref_add+0x30/0x30 [lod] [ 568.190272] ? lod_trans_start+0x109/0x4c0 [lod] [ 568.192353] ? mdd_declare_attr_set+0x148/0x380 [mdd] [ 568.194067] ? mdd_trans_start+0x18/0x30 [mdd] [ 568.195177] ? mdd_attr_set+0xa5a/0x1240 [mdd] [ 568.196515] ? mdt_reint_setattr+0x1342/0x1f90 [mdt] [ 568.198779] ? mdt_reint_setattr+0x1342/0x1f90 [mdt] [ 568.200523] ? mdt_reint_rec+0x139/0x2b0 [mdt] [ 568.201464] ? mdt_reint_internal+0x6a0/0xdc0 [mdt] [ 568.202812] ? mdt_reint+0x163/0x190 [mdt] [ 568.204678] ? tgt_handle_request0+0x137/0xaf0 [ptlrpc] [ 568.206063] ? tgt_request_handle+0x351/0x1c00 [ptlrpc] [ 568.207433] ? ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [ 568.209047] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [ 568.210336] ? ptlrpc_main+0xd1e/0x1440 [ptlrpc] [ 568.211675] ? ptlrpc_wait_event+0x980/0x980 [ptlrpc] [ 568.212979] ? kthread+0x1d1/0x200 [ 568.213819] ? set_kthread_struct+0x70/0x70 [ 568.214600] ? ret_from_fork+0x1f/0x30 [ 568.825874] Lustre: DEBUG MARKER: Write... [ 572.483990] Lustre: DEBUG MARKER: Write out of block quota ... [ 605.119667] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 12:25:00 (1752510300) [ 609.231294] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 611.011863] Lustre: DEBUG MARKER: Write 5MiB Using Fallocate [ 614.484500] Lustre: DEBUG MARKER: Write 11MiB Using Fallocate [ 629.379664] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 12:25:25 (1752510325) [ 633.259848] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 640.221474] Lustre: DEBUG MARKER: Write... [ 640.953891] Lustre: DEBUG MARKER: Write out of block quota ... [ 658.925271] Lustre: DEBUG MARKER: Write... [ 659.720253] Lustre: DEBUG MARKER: Write out of block quota ... [ 666.358313] LustreError: 23901:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:14344 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 685.250148] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 12:26:20 (1752510380) [ 688.904404] Lustre: DEBUG MARKER: -------------------------------------- [ 689.400249] Lustre: DEBUG MARKER: Project quota (block hardlimit:40 mb) [ 796.402795] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 796.970341] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 12:28:12 (1752510492) [ 827.404538] Lustre: DEBUG MARKER: Write after timer goes off [ 827.961499] Lustre: DEBUG MARKER: Write after cancel lru locks [ 877.229123] Lustre: DEBUG MARKER: Write after timer goes off [ 877.799172] Lustre: DEBUG MARKER: Write after cancel lru locks [ 928.846942] Lustre: DEBUG MARKER: Write after timer goes off [ 930.280415] Lustre: DEBUG MARKER: Write after cancel lru locks [ 963.766674] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 12:30:59 (1752510659) [ 998.377526] Lustre: DEBUG MARKER: Write after timer goes off [ 998.936922] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1046.956873] Lustre: DEBUG MARKER: Write after timer goes off [ 1048.478159] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1097.959823] Lustre: DEBUG MARKER: Write after timer goes off [ 1099.444823] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1140.880235] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 12:33:56 (1752510836) [ 1180.495065] Lustre: DEBUG MARKER: Write after timer goes off [ 1181.036859] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1222.980809] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 1223.494025] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 12:35:19 (1752510919) [ 1226.933305] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 1230.181512] LustreError: 69605:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 1270.274032] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 12:36:05 (1752510965) [ 1290.769346] Lustre: *** cfs_fail_loc=513, val=601*** [ 1291.167399] LustreError: 15700:0:(service.c:2318:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1837639665023232 [ 1292.768543] Lustre: *** cfs_fail_loc=513, val=601*** [ 1292.771248] Lustre: Skipped 30 previous similar messages [ 1293.792691] Lustre: *** cfs_fail_loc=513, val=601*** [ 1293.795149] Lustre: Skipped 5 previous similar messages [ 1296.352510] Lustre: *** cfs_fail_loc=513, val=601*** [ 1296.354463] Lustre: Skipped 5 previous similar messages [ 1301.409376] Lustre: *** cfs_fail_loc=513, val=601*** [ 1301.412214] Lustre: Skipped 13 previous similar messages [ 1306.592543] Lustre: 40199:0:(service.c:1606:ptlrpc_at_send_early_reply()) @@@ Could not add any time (5/5), not sending early reply req@ffff9981051a1c00 x1837639658671360/t0(0) o4->5632e628-d5dc-4a38-b39e-cdb17b3a8f7a@192.168.201.26@tcp:477/0 lens 488/448 e 1 to 0 dl 1752511007 ref 2 fl Interpret:/600/0 rc 0/0 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 1307.616236] Lustre: 18664:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1752510987/real 1752510987] req@ffff9981064a8a80 x1837639665023232/t0(0) o601->lustre-MDT0000-lwp-OST0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1752511003 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 1307.630505] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1307.642725] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0001_UUID (at 0@lo) reconnecting [ 1307.647936] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 1307.704737] LustreError: 15700:0:(service.c:2318:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1837639665033600 [ 1311.712653] Lustre: *** cfs_fail_loc=513, val=601*** [ 1311.714694] Lustre: Skipped 65 previous similar messages [ 1324.000128] Lustre: 3607:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1752511003/real 1752511003] req@ffff998104e24e00 x1837639665033600/t0(0) o601->lustre-MDT0000-lwp-OST0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1752511019 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 1324.006583] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1324.012520] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0001_UUID (at 0@lo) reconnecting [ 1324.016724] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 1327.517155] LustreError: 15700:0:(service.c:2318:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1837639665043712 [ 1328.608509] Lustre: *** cfs_fail_loc=513, val=601*** [ 1328.610082] Lustre: Skipped 89 previous similar messages [ 1343.968150] Lustre: 18664:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1752511023/real 1752511023] req@ffff998104b7b480 x1837639665043712/t0(0) o601->lustre-MDT0000-lwp-OST0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1752511039 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 1343.975424] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1343.981852] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0001_UUID (at 0@lo) reconnecting [ 1343.983889] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 1362.744636] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 12:37:38 (1752511058) [ 1372.059775] Lustre: Failing over lustre-OST0000 [ 1372.079906] LustreError: 75364:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 1372.100273] Lustre: server umount lustre-OST0000 complete [ 1374.689815] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 1374.691970] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1374.694920] Lustre: Skipped 1 previous similar message [ 1375.013778] LustreError: 75683:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 1375.016779] LustreError: 75683:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 11 previous similar messages [ 1377.318906] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1377.402153] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 1377.410882] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1378.661736] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 1379.234426] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1379.315141] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 1379.315673] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 192.168.201.126@tcp (at 0@lo) [ 1381.627509] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1383.184539] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1384.765020] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1386.344992] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1387.941921] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1389.424514] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1405.462228] Lustre: Failing over lustre-OST0000 [ 1405.481075] LustreError: 78966:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 1405.484722] LustreError: 78966:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1405.502601] Lustre: server umount lustre-OST0000 complete [ 1406.371119] LustreError: 40386:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.201.26@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1406.379689] LustreError: 40386:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 4 previous similar messages [ 1408.484895] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1408.485488] LustreError: 40386:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1408.488645] Lustre: Skipped 1 previous similar message [ 1408.823757] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1408.965555] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 1408.975929] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1410.165347] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 1410.666124] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 192.168.201.126@tcp (at 0@lo) [ 1410.666254] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 1410.669387] Lustre: Skipped 1 previous similar message [ 1411.254538] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1414.110596] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1415.885970] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1418.004165] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1419.718566] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1421.780119] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1423.683349] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1439.452092] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 12:38:55 (1752511135) [ 1451.749956] LustreError: 83611:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 1451.754419] LustreError: 83611:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 14 previous similar messages [ 1453.001993] Lustre: *** cfs_fail_loc=a02, val=0*** [ 1454.900604] LustreError: 3605:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -5, flags:0x8 qsd:lustre-OST0000 qtype:usr id:60000 enforced:1 granted: 1024 pending:0 waiting:0 req:1 usage: 2048 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 1454.908579] Lustre: Failing over lustre-OST0000 [ 1454.926108] LustreError: 83991:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 1454.929046] LustreError: 83991:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1454.947200] Lustre: server umount lustre-OST0000 complete [ 1455.074887] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1455.075801] LustreError: 40384:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1455.078149] Lustre: Skipped 1 previous similar message [ 1455.082914] LustreError: 40384:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 1 previous similar message [ 1457.568213] LustreError: 40386:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.201.26@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1457.577488] LustreError: 40386:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 1 previous similar message [ 1457.944081] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1458.038606] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 1458.047198] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1459.236388] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 1459.766449] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 1459.766458] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 192.168.201.126@tcp (at 0@lo) [ 1459.766464] Lustre: Skipped 1 previous similar message [ 1459.908969] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1462.388268] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1464.377874] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1466.195827] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1468.010193] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1469.771608] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1471.779265] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1488.144409] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 12:39:43 (1752511183) [ 1495.141381] LustreError: 88574:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 1495.147107] LustreError: 88574:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 17 previous similar messages [ 1496.501627] LustreError: 88762:0:(qsd_reint.c:475:qsd_reint_main()) cfs_fail_timeout id a03 sleeping for 10000ms [ 1496.506033] LustreError: 88762:0:(qsd_reint.c:475:qsd_reint_main()) Skipped 5 previous similar messages [ 1497.070171] Lustre: Failing over lustre-MDT0000 [ 1497.563252] LustreError: 88864:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 1497.564884] LustreError: 88864:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1497.601346] Lustre: server umount lustre-MDT0000 complete [ 1498.525925] LustreError: 6444:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.26@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1498.552056] LustreError: 88762:0:(qsd_reint.c:475:qsd_reint_main()) cfs_fail_timeout interrupted [ 1498.553718] LustreError: lustre-MDT0000-lwp-OST0001: operation dt_index_read to node 0@lo failed: rc = -107 [ 1498.553793] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1498.553880] LustreError: 88762:0:(qsd_reint.c:475:qsd_reint_main()) Skipped 3 previous similar messages [ 1498.555676] LustreError: Skipped 3 previous similar messages [ 1500.451888] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1500.494594] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1500.588383] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1500.618234] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1501.727922] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1503.641926] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1503.993813] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1505.765107] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 1505.766852] Lustre: Skipped 1 previous similar message [ 1505.768382] LustreError: 3603:0:(ldlm_resource.c:981:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x2020000:0x0].0x0 (ffff998102dc7e00) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 1505.791256] Lustre: 88767:0:(qsd_reint.c:241:qsd_reint_index()) lustre-OST0001: index version for fid [0x200000005:0x100c:0x0] is 0, but index isn't empty (1) [ 1505.799231] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 1505.816530] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:150 to 0x280000401:193) [ 1505.816552] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:106 to 0x2c0000401:129) [ 1616.508496] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1617.968733] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1619.433024] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1620.930203] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1622.426886] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1637.111929] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 12:42:12 (1752511332) [ 1642.454160] LustreError: 97422:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0001: Delaying reintegration for qtype:0 until pending updates are flushed. [ 1642.457037] LustreError: 97422:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 17 previous similar messages [ 1644.364967] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 1645.889149] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 1662.622991] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 12:42:38 (1752511358) [ 1671.093679] Lustre: Failing over lustre-MDT0001 [ 1671.160050] LustreError: 100098:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 1671.161704] LustreError: 100098:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1671.184725] Lustre: server umount lustre-MDT0001 complete [ 1672.609070] LustreError: 6442:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.201.26@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1672.613377] LustreError: 6442:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 7 previous similar messages [ 1673.701056] LustreError: 100370:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-OST0001: Delaying reintegration for qtype:0 until pending updates are flushed. [ 1673.704335] LustreError: 100370:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 5 previous similar messages [ 1674.720819] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 1674.722170] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1674.724229] LustreError: Skipped 1 previous similar message [ 1674.727928] Lustre: Skipped 4 previous similar messages [ 1676.257248] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1676.391259] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1676.415247] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1677.573098] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1677.721371] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1679.916926] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1681.513112] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 1681.896640] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to (at 0@lo) [ 1681.898105] Lustre: Skipped 3 previous similar messages [ 1681.903632] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 1681.924319] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 1688.104908] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1689.732523] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 1691.322788] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1692.912109] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 1746.880685] Lustre: Failing over lustre-MDT0001 [ 1747.029148] LustreError: 103255:0:(obd_class.h:479:obd_check_dev()) Device 21 not setup [ 1747.035471] LustreError: 103255:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1747.108054] Lustre: server umount lustre-MDT0001 complete [ 1748.449564] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 1748.450547] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1748.451776] LustreError: 6442:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1748.451783] LustreError: 6442:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 3 previous similar messages [ 1748.483418] Lustre: Skipped 3 previous similar messages [ 1752.237778] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1752.541199] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1752.565130] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1754.292853] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1754.321904] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1757.671658] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to (at 0@lo) [ 1757.674276] Lustre: Skipped 2 previous similar messages [ 1757.686620] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 1757.710320] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 1757.754112] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1760.333293] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 1762.917226] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1765.526852] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 1768.059995] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 1770.354053] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 1806.946816] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 12:45:02 (1752511502) [ 1812.582682] LustreError: 106907:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-OST0001: Delaying reintegration for qtype:1 until pending updates are flushed. [ 1812.586766] LustreError: 106907:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 5 previous similar messages [ 1975.797856] Lustre: DEBUG MARKER: == sanity-quota test 9: Block limit larger than 4GB (b10707) ========================================================== 12:47:51 (1752511671) [ 1976.466315] Lustre: DEBUG MARKER: OST0_SIZE: 3600016 required: 4900000 [ 1979.229936] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 12:47:54 (1752511674) [ 2001.561892] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 12:48:17 (1752511697) [ 2022.095375] Lustre: DEBUG MARKER: == sanity-quota test 12a: Block quota rebalancing ======== 12:48:37 (1752511717) [ 2058.562727] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 12:49:14 (1752511754) [ 2107.151572] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 12:50:02 (1752511802) [ 2129.664408] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 12:50:25 (1752511825) [ 2133.801397] LustreError: 117028:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-OST0001: Delaying reintegration for qtype:1 until pending updates are flushed. [ 2133.808205] LustreError: 117028:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 9 previous similar messages [ 2140.264938] Lustre: Failing over lustre-OST0000 [ 2140.292047] LustreError: 117461:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 2140.293588] LustreError: 117461:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2140.318383] Lustre: server umount lustre-OST0000 complete [ 2140.641914] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2140.645749] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2140.650248] LustreError: 40384:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2140.656723] LustreError: 40384:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 3 previous similar messages [ 2146.603449] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2146.763255] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 2146.774842] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2147.820566] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 2148.016268] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 2148.017035] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 192.168.201.126@tcp (at 0@lo) [ 2148.025500] Lustre: Skipped 2 previous similar messages [ 2148.892425] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2168.428466] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 12:51:04 (1752511864) [ 2178.432390] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 12:51:13 (1752511873) [ 2185.591074] Lustre: lustre-MDT0001: Client 5632e628-d5dc-4a38-b39e-cdb17b3a8f7a (at 192.168.201.26@tcp) reconnecting [ 2201.188757] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 12:51:36 (1752511896) [ 2201.802773] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 2202.404554] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 12:51:38 (1752511898) [ 2210.510540] Lustre: *** cfs_fail_loc=a04, val=37*** [ 2210.511904] LustreError: 40149:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0000 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 2211.551595] Lustre: *** cfs_fail_loc=a04, val=37*** [ 2211.553979] LustreError: 40149:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0000 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 2234.889849] Lustre: *** cfs_fail_loc=a04, val=11*** [ 2259.164834] Lustre: *** cfs_fail_loc=a04, val=110*** [ 2259.166817] Lustre: Skipped 1 previous similar message [ 2285.294479] Lustre: *** cfs_fail_loc=a04, val=107*** [ 2285.296524] Lustre: Skipped 1 previous similar message [ 2318.309228] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 12:53:34 (1752512014) [ 2323.665657] Lustre: DEBUG MARKER: User quota (limit: 200) [ 2325.124818] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 2327.928925] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2328.460147] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 2329.102296] Lustre: Failing over lustre-MDT0000 [ 2329.450889] LustreError: 130784:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 2329.453685] LustreError: 130784:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2329.484498] Lustre: server umount lustre-MDT0000 complete [ 2329.909483] LustreError: lustre-MDT0000-lwp-OST0000: operation quota_acquire to node 0@lo failed: rc = -107 [ 2329.911875] LustreError: Skipped 1 previous similar message [ 2329.913637] LustreError: 10043:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2329.918863] LustreError: 10043:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 3 previous similar messages [ 2343.923705] LDISKFS-fs (dm-0): recovery complete [ 2343.925655] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2343.964581] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2344.046686] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2344.096366] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2345.411508] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2347.418777] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2349.550866] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 2349.566169] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1240 to 0x2c0000401:1281) [ 2349.566316] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1306 to 0x280000401:1345) [ 2350.762369] Lustre: DEBUG MARKER: oleg126-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2351.331845] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2361.006885] Lustre: DEBUG MARKER: (dd_pid=111993, time=7, timeout=600) [ 2376.796720] Lustre: DEBUG MARKER: User quota (limit: 200) [ 2378.330251] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 2381.121576] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2381.701080] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 2382.392355] Lustre: Failing over lustre-MDT0000 [ 2382.681850] Lustre: server umount lustre-MDT0000 complete [ 2385.376701] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2385.378869] LustreError: Skipped 1 previous similar message [ 2396.828779] LDISKFS-fs (dm-0): recovery complete [ 2396.829868] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2396.864196] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2396.950061] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2398.186508] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2402.299406] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1347 to 0x280000401:1377) [ 2402.299466] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1240 to 0x2c0000401:1313) [ 2403.443085] Lustre: DEBUG MARKER: oleg126-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2404.003698] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2406.382544] Lustre: DEBUG MARKER: (dd_pid=114428, time=0, timeout=600) [ 2419.182523] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 12:55:14 (1752512114) [ 2441.618545] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 12:55:37 (1752512137) [ 2446.304477] LustreError: 103728:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0001: Delaying reintegration for qtype:1 until pending updates are flushed. [ 2446.307830] LustreError: 103728:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 9 previous similar messages [ 2449.157298] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 2452.755206] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 2453.303847] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 2453.855822] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 2454.484085] Lustre: DEBUG MARKER: Set quota for 1 times [ 2456.142399] Lustre: DEBUG MARKER: Set quota for 2 times [ 2457.763765] Lustre: DEBUG MARKER: Set quota for 3 times [ 2459.446417] Lustre: DEBUG MARKER: Set quota for 4 times [ 2461.036890] Lustre: DEBUG MARKER: Set quota for 5 times [ 2462.691651] Lustre: DEBUG MARKER: Set quota for 6 times [ 2464.439913] Lustre: DEBUG MARKER: Set quota for 7 times [ 2466.119867] Lustre: DEBUG MARKER: Set quota for 8 times [ 2467.699939] Lustre: DEBUG MARKER: Set quota for 9 times [ 2469.386854] Lustre: DEBUG MARKER: Set quota for 10 times [ 2470.993347] Lustre: DEBUG MARKER: Set quota for 11 times [ 2472.583386] Lustre: DEBUG MARKER: Set quota for 12 times [ 2474.298281] Lustre: DEBUG MARKER: Set quota for 13 times [ 2475.906527] Lustre: DEBUG MARKER: Set quota for 14 times [ 2477.635720] Lustre: DEBUG MARKER: Set quota for 15 times [ 2479.249866] Lustre: DEBUG MARKER: Set quota for 16 times [ 2480.909724] Lustre: DEBUG MARKER: Set quota for 17 times [ 2482.616543] Lustre: DEBUG MARKER: Set quota for 18 times [ 2484.244300] Lustre: DEBUG MARKER: Set quota for 19 times [ 2508.765973] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 12:56:44 (1752512204) [ 2514.913235] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2514.913741] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2514.918173] Lustre: Skipped 12 previous similar messages [ 2514.918342] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2514.921372] Lustre: Skipped 3 previous similar messages [ 2516.217739] LustreError: 141760:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 2516.220726] LustreError: 141760:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 2516.248659] Lustre: server umount lustre-MDT0000 complete [ 2517.467614] LustreError: 6428:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752512213 with bad export cookie 2002052619567708317 [ 2517.469433] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2517.471816] LustreError: 6428:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2517.632103] Lustre: server umount lustre-MDT0001 complete [ 2528.193826] Lustre: server umount lustre-OST0000 complete [ 2539.878487] Lustre: server umount lustre-OST0001 complete [ 2545.447534] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 2549.480311] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2549.658845] LustreError: 143524:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2549.674902] LustreError: 143524:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 30 previous similar messages [ 2549.694451] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2551.114822] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2554.368688] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2555.879291] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2556.910728] Lustre: 144633:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2559.303669] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2560.483972] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1380 to 0x280000401:1409) [ 2561.576506] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2564.827235] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2566.641862] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:97) [ 2566.652193] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1315 to 0x2c0000401:1345) [ 2567.126369] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2570.418908] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2571.732891] Lustre: 146472:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2585.851712] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2585.854349] Lustre: Skipped 3 previous similar messages [ 2591.200563] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2591.203036] Lustre: Skipped 3 previous similar messages [ 2592.019855] Lustre: server umount lustre-MDT0000 complete [ 2593.297058] LustreError: 143505:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752512289 with bad export cookie 2002052619567718278 [ 2593.298862] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2593.300532] LustreError: 143505:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2593.436877] Lustre: server umount lustre-MDT0001 complete [ 2604.545320] Lustre: server umount lustre-OST0000 complete [ 2616.174850] Lustre: server umount lustre-OST0001 complete [ 2621.611794] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 2625.055808] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2625.230599] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2625.232425] Lustre: Skipped 3 previous similar messages [ 2626.467446] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2629.198679] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2630.557961] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2631.592455] Lustre: 150237:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2633.851299] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2635.861684] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2636.003183] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1380 to 0x280000401:1441) [ 2638.854963] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2639.972407] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1315 to 0x2c0000401:1377) [ 2639.986914] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:129) [ 2640.754810] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2643.822601] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2644.951140] Lustre: 152071:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2653.267834] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 12:59:08 (1752512348) [ 2653.772903] Lustre: DEBUG MARKER: OST0_SIZE: 3605408 required: 6144 [ 2654.282266] Lustre: DEBUG MARKER: run for 4MB test file [ 2659.069045] Lustre: DEBUG MARKER: User quota (limit: 4 MB) [ 2660.628555] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 2661.238206] Lustre: DEBUG MARKER: Write half of file [ 2661.862372] Lustre: DEBUG MARKER: Write out of block quota ... [ 2662.476559] Lustre: DEBUG MARKER: Step1: done [ 2663.104908] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 2663.683348] Lustre: DEBUG MARKER: Step2: done [ 2675.823081] Lustre: DEBUG MARKER: OST0_SIZE: 3605408 required: 61440 [ 2676.335720] Lustre: DEBUG MARKER: run for 40MB test file [ 2680.197996] Lustre: DEBUG MARKER: User quota (limit: 40 MB) [ 2681.791770] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 2682.357242] Lustre: DEBUG MARKER: Write half of file [ 2683.341418] Lustre: DEBUG MARKER: Write out of block quota ... [ 2684.247963] Lustre: DEBUG MARKER: Step1: done [ 2684.789321] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 2685.363743] Lustre: DEBUG MARKER: Step2: done [ 2705.920380] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 13:00:01 (1752512401) [ 2726.376804] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 13:00:22 (1752512422) [ 2739.337114] Lustre: DEBUG MARKER: Write... [ 2740.077233] Lustre: DEBUG MARKER: Write out of block quota ... [ 2771.216089] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 13:01:05 (1752512465) [ 2776.377486] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 13:01:11 (1752512471) [ 2783.892631] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 13:01:19 (1752512479) [ 2789.907671] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 13:01:25 (1752512485) [ 2794.022964] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 13:01:29 (1752512489) [ 2824.712614] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 2875.728283] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 2941.322967] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 13:03:56 (1752512636) [ 2960.656630] Lustre: DEBUG MARKER: Restart... [ 2962.400803] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2962.403907] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2967.999702] LustreError: 172070:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 2968.001710] LustreError: 172070:0:(obd_class.h:479:obd_check_dev()) Skipped 51 previous similar messages [ 2968.030845] Lustre: server umount lustre-MDT0000 complete [ 2968.034951] LustreError: 149140:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2968.041469] LustreError: 149140:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 8 previous similar messages [ 2969.379301] LustreError: 149862:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752512665 with bad export cookie 2002052619567720581 [ 2969.381726] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2969.384496] LustreError: 149862:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2969.535509] Lustre: server umount lustre-MDT0001 complete [ 2980.353907] Lustre: server umount lustre-OST0000 complete [ 2991.978444] Lustre: server umount lustre-OST0001 complete [ 2997.019626] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 3000.283438] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3000.437479] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3000.439447] Lustre: Skipped 3 previous similar messages [ 3001.776032] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3004.558384] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3006.122163] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3007.194244] Lustre: 174932:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3009.545481] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3010.724924] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1452 to 0x280000401:1473) [ 3011.754512] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3014.862278] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3016.687284] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:161) [ 3016.694643] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1386 to 0x2c0000401:1409) [ 3016.947531] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3020.365874] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3021.629422] Lustre: 176766:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3047.042058] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 13:05:42 (1752512742) [ 3075.112585] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 13:06:10 (1752512770) [ 3532.291791] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 13:13:48 (1752513228) [ 3537.379953] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3537.380778] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3537.381778] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3537.381785] Lustre: Skipped 3 previous similar messages [ 3537.385781] Lustre: Skipped 11 previous similar messages [ 3541.397905] LustreError: 182012:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 3541.401069] LustreError: 182012:0:(obd_class.h:479:obd_check_dev()) Skipped 25 previous similar messages [ 3541.462819] Lustre: server umount lustre-MDT0000 complete [ 3542.498965] LustreError: 173830:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3542.508360] LustreError: 173830:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 7 previous similar messages [ 3542.757401] LustreError: 173814:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752513238 with bad export cookie 2002052619567729471 [ 3542.760465] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3542.761667] LustreError: 173814:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3542.902991] Lustre: server umount lustre-MDT0001 complete [ 3554.832721] Lustre: server umount lustre-OST0000 complete [ 3565.373506] Lustre: server umount lustre-OST0001 complete [ 3569.894421] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 3573.080880] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3573.249040] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3573.250853] Lustre: Skipped 3 previous similar messages [ 3574.514354] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3577.420590] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3578.832210] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3579.892527] Lustre: 184876:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3582.179451] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3583.336905] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:6476 to 0x280000401:6497) [ 3584.308528] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3587.811720] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3589.873457] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:193) [ 3589.878525] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:6410 to 0x2c0000401:6433) [ 3590.017765] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3593.602687] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3612.525412] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 13:15:08 (1752513308) [ 3624.196174] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 13:15:19 (1752513319) [ 3637.640256] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 13:15:33 (1752513333) [ 3653.299405] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 13:15:49 (1752513349) [ 3669.386885] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 13:16:05 (1752513365) [ 3673.702471] LustreError: 192333:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 3673.706887] LustreError: 192333:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 9 previous similar messages [ 3705.680147] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 13:16:41 (1752513401) [ 3716.414430] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 13:16:52 (1752513412) [ 3723.173177] LustreError: 185236:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -3, flags:0x1 qsd:lustre-OST0000 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 3723.179987] LustreError: 185236:0:(qsd_handler.c:794:qsd_op_begin0()) $$$ ID isn't enforced on master, it probably due to a legeal race, if this message is showing up constantly, there could be some inconsistence between master & slave, and quota reintegration needs be re-triggered. qsd:lustre-OST0000 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:0 req:0 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 3756.405423] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 13:17:32 (1752513452) [ 3758.261879] Lustre: *** cfs_fail_loc=a09, val=0*** [ 3758.263520] Lustre: Skipped 1 previous similar message [ 3759.265634] Lustre: *** cfs_fail_loc=a09, val=0*** [ 3759.267121] Lustre: Skipped 181 previous similar messages [ 3761.265239] Lustre: *** cfs_fail_loc=a09, val=0*** [ 3761.267198] Lustre: Skipped 367 previous similar messages [ 3765.270788] Lustre: *** cfs_fail_loc=a09, val=0*** [ 3765.271844] Lustre: Skipped 739 previous similar messages [ 3773.271158] Lustre: *** cfs_fail_loc=a09, val=0*** [ 3773.272542] Lustre: Skipped 1452 previous similar messages [ 3789.272647] Lustre: *** cfs_fail_loc=a09, val=0*** [ 3789.274583] Lustre: Skipped 2648 previous similar messages [ 3920.866170] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3920.868294] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3920.874223] Lustre: Skipped 6 previous similar messages [ 3923.768136] Lustre: server umount lustre-MDT0000 complete [ 3925.036585] LustreError: 184498:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752513620 with bad export cookie 2002052619569471974 [ 3925.040404] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3925.040759] LustreError: 184498:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3939.296122] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 3939.296941] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3939.300933] Lustre: Skipped 7 previous similar messages [ 3939.406025] Lustre: server umount lustre-MDT0001 complete [ 3941.030914] Lustre: server umount lustre-OST0000 complete [ 3942.596715] Lustre: server umount lustre-OST0001 complete [ 3944.876047] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_hostid [ 3947.486905] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 3952.750493] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3956.534184] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3958.774385] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3961.313463] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3966.075971] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 3969.815755] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3969.851842] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3969.962949] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3969.977513] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3970.024815] Lustre: lustre-MDT0000: new disk, initializing [ 3970.058956] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3970.060986] Lustre: Skipped 3 previous similar messages [ 3970.068474] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3971.524262] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3975.962231] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3976.000208] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3976.028027] Lustre: 202623:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3976.031699] Lustre: 202623:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 3976.041053] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3976.042751] Lustre: Skipped 1 previous similar message [ 3976.085642] Lustre: lustre-MDT0001: new disk, initializing [ 3976.117462] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3976.120536] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3977.505391] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3979.877576] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3982.238365] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3982.263360] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3982.338106] Lustre: lustre-OST0000: new disk, initializing [ 3982.341197] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3983.790219] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3983.794866] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3983.805031] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3984.370285] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3988.683770] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3988.714281] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3988.758430] Lustre: lustre-OST0001: new disk, initializing [ 3988.760244] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3990.318223] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3990.322618] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3990.341087] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3990.888974] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3995.515055] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3996.777407] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4010.812409] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 13:21:46 (1752513706) [ 4012.889335] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 13:21:48 (1752513708) [ 4025.127562] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 13:22:00 (1752513720) [ 4044.657482] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 13:22:20 (1752513740) [ 4050.756969] Lustre: DEBUG MARKER: rename directory return 255 [ 4069.310581] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 13:22:45 (1752513765) [ 4076.105746] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 13:22:51 (1752513771) [ 4085.920296] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 13:23:01 (1752513781) [ 4115.418333] LustreError: 202630:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-0x0 id:60001 enforced:1 hard:51200 soft:0 granted:51200 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 4128.061539] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 13:23:43 (1752513823) [ 4137.324154] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 13:23:53 (1752513833) [ 4154.910297] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 13:24:10 (1752513850) [ 4219.888035] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 13:25:15 (1752513915) [ 4221.921737] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4221.927601] Lustre: Skipped 6 previous similar messages [ 4221.930494] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4227.411066] LustreError: 219164:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 4227.414259] LustreError: 219164:0:(obd_class.h:479:obd_check_dev()) Skipped 51 previous similar messages [ 4227.468763] Lustre: server umount lustre-MDT0000 complete [ 4229.215307] LustreError: 202613:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752513925 with bad export cookie 2002052619569843884 [ 4229.220743] LustreError: 202613:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 4229.221173] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4229.377421] Lustre: server umount lustre-MDT0001 complete [ 4240.333240] Lustre: server umount lustre-OST0000 complete [ 4252.147716] Lustre: server umount lustre-OST0001 complete [ 4258.556647] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 4261.858294] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4261.987964] LustreError: 221131:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4261.996479] LustreError: 221131:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 12 previous similar messages [ 4262.009346] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4262.012305] Lustre: Skipped 3 previous similar messages [ 4262.014835] LustreError: lustre-MDT0000: can't enable quota enforcement since space accounting isn't functional. Please run tunefs.lustre --quota on an unmounted filesystem if not done already [ 4263.275798] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4266.217329] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4266.332979] LustreError: lustre-MDT0001: can't enable quota enforcement since space accounting isn't functional. Please run tunefs.lustre --quota on an unmounted filesystem if not done already [ 4267.839188] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4268.925263] Lustre: 222231:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4271.844134] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4271.994296] LustreError: lustre-OST0000: can't enable quota enforcement since space accounting isn't functional. Please run tunefs.lustre --quota on an unmounted filesystem if not done already [ 4274.432719] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4277.947162] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4278.012128] LustreError: lustre-OST0001: can't enable quota enforcement since space accounting isn't functional. Please run tunefs.lustre --quota on an unmounted filesystem if not done already [ 4280.238469] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4286.564749] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:65) [ 4286.564930] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:20 to 0x280000401:65) [ 4294.502897] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4303.565154] LustreError: 221125:0:(osd_handler.c:3264:osd_quota_transfer()) lustre-MDT0000: quota transfer failed. Is project enforcement enabled on the ldiskfs filesystem? rc = -95 [ 4307.428384] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4307.430292] Lustre: Skipped 7 previous similar messages [ 4311.004896] Lustre: server umount lustre-MDT0000 complete [ 4312.684067] LustreError: 221110:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752514008 with bad export cookie 2002052619569892653 [ 4312.684560] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4312.692151] LustreError: 221110:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4312.875288] Lustre: server umount lustre-MDT0001 complete [ 4324.962765] Lustre: server umount lustre-OST0000 complete [ 4339.699663] Lustre: server umount lustre-OST0001 complete [ 4359.689647] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 4376.179589] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4384.079731] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4398.105667] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4405.988495] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4410.565712] Lustre: 227565:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4410.570021] Lustre: 227565:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 4419.532228] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4423.036140] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:67 to 0x280000401:97) [ 4426.286526] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4435.581283] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4437.334719] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:97) [ 4441.935694] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4449.790938] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4481.302860] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 13:29:35 (1752514175) [ 4489.151372] LustreError: 230550:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 4489.156285] LustreError: 230550:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 7 previous similar messages [ 4520.661311] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [ 4522.239566] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 13:30:17 (1752514217) [ 4540.452472] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [ 4542.092540] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non dir/files should succeed ========================================================== 13:30:36 (1752514236) [ 4575.634256] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [ 4577.217401] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 13:31:12 (1752514272) [ 4605.885607] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 13:31:40 (1752514300) [ 4616.408977] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 4620.327673] Lustre: 235532:0:(qsd_reint.c:241:qsd_reint_index()) lustre-OST0000: index version for fid [0x200000005:0x1008:0x0] is 0, but index isn't empty (1) [ 4620.349660] Lustre: 235532:0:(qsd_reint.c:241:qsd_reint_index()) Skipped 1 previous similar message [ 4623.771656] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 4628.537391] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 4631.691431] Lustre: DEBUG MARKER: Write... [ 4649.383956] LustreError: 236733:0:(mgs_handler.c:928:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [ 4655.073257] Lustre: DEBUG MARKER: Write... [ 4664.163534] Lustre: DEBUG MARKER: Write... [ 4740.404403] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 13:33:54 (1752514434) [ 4765.911936] LustreError: 240220:0:(mgs_handler.c:928:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [ 4806.201584] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 13:35:01 (1752514501) [ 4815.681765] LustreError: 242407:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:2 until pending updates are flushed. [ 4815.698967] LustreError: 242407:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 7 previous similar messages [ 4826.232717] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 4827.558654] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 4894.431339] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 13:36:29 (1752514589) [ 4931.387072] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 13:37:06 (1752514626) [ 4962.483808] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 13:37:37 (1752514657) [ 4973.621644] Lustre: DEBUG MARKER: User quota (block hardlimit:100 MB) [ 4994.724569] Lustre: DEBUG MARKER: Write... [ 4996.133695] Lustre: DEBUG MARKER: Write out of block quota ... [ 5069.237063] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 13:39:24 (1752514764) [ 5079.083922] Lustre: DEBUG MARKER: User quota (block hardlimit:1000 MB) [ 5149.326554] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 13:40:44 (1752514844) [ 5160.966812] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [ 5177.789901] Lustre: DEBUG MARKER: Write... [ 5179.719823] Lustre: DEBUG MARKER: Write out of block quota ... [ 5180.112803] LustreError: 226458:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:10240 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 5222.024413] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 13:41:56 (1752514916) [ 5247.363423] Lustre: DEBUG MARKER: set to use default quota [ 5249.054573] Lustre: DEBUG MARKER: set default quota [ 5250.780029] Lustre: DEBUG MARKER: get default quota [ 5255.444247] Lustre: DEBUG MARKER: Test not out of quota [ 5259.050608] Lustre: DEBUG MARKER: Test out of quota [ 5267.839914] Lustre: DEBUG MARKER: Increase default quota [ 5285.479242] Lustre: DEBUG MARKER: Set quota to override default quota [ 5285.540494] LustreError: 228126:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:20480 soft:20480 granted:45056 time:1753119781 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 5295.947686] Lustre: DEBUG MARKER: Set to use default quota again [ 5312.752484] Lustre: DEBUG MARKER: Cleanup [ 5361.134700] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 13:44:15 (1752515055) [ 5381.844360] Lustre: DEBUG MARKER: set default quota for qpool1 [ 5383.423923] Lustre: DEBUG MARKER: Write from user that hasn't lqe [ 5419.397566] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 13:45:14 (1752515114) [ 5482.617778] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 13:46:17 (1752515177) [ 5572.191289] Lustre: DEBUG MARKER: Write... [ 5575.203319] Lustre: DEBUG MARKER: Write out of block quota ... [ 5690.432613] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 13:49:45 (1752515385) [ 5718.388546] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 13:50:13 (1752515413) [ 5724.824820] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 13:50:19 (1752515419) [ 5750.782304] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 13:50:45 (1752515445) [ 5788.303469] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 13:51:22 (1752515482) [ 5812.055933] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 13:51:46 (1752515506) [ 5833.710647] Lustre: *** cfs_fail_loc=a06, val=0*** [ 5833.712472] Lustre: Skipped 2607 previous similar messages [ 5833.908060] LustreError: 226475:0:(qmt_lock.c:446:qmt_lvbo_update()) $$$ failed to release quota space on glimpse 0!=2048 : rc = -11 [ 5833.908060] qmt:lustre-QMT0000 pool:dt-0x0 id:60000 enforced:1 hard:102400 soft:0 granted:23552 time:0 qunit: 16384 edquot:0 may_rel:0 revoke:0 default:no [ 5837.714396] Lustre: *** cfs_fail_loc=a06, val=0*** [ 5837.722267] Lustre: Skipped 1777 previous similar messages [ 5838.813081] Lustre: Failing over lustre-OST0001 [ 5838.817550] Lustre: lustre-OST0001-osc-MDT0000: Connection to lustre-OST0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5838.831485] Lustre: Skipped 7 previous similar messages [ 5838.841332] Lustre: lustre-OST0001: Not available for connect from 0@lo (stopping) [ 5840.892606] LustreError: 274033:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 5840.902588] LustreError: 274033:0:(obd_class.h:479:obd_check_dev()) Skipped 51 previous similar messages [ 5840.991366] Lustre: server umount lustre-OST0001 complete [ 5841.848254] LustreError: 228806:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-OST0001: not available for connect from 192.168.201.26@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5841.859606] LustreError: 228806:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 18 previous similar messages [ 5848.566929] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5848.890155] Lustre: lustre-OST0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 5848.908328] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [ 5848.912667] Lustre: Skipped 1 previous similar message [ 5850.000564] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 5850.004503] Lustre: Skipped 1 previous similar message [ 5850.208834] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 5850.209142] Lustre: lustre-OST0001-osc-MDT0000: Connection restored to 192.168.201.126@tcp (at 0@lo) [ 5850.215837] Lustre: Skipped 1 previous similar message [ 5850.222633] Lustre: Skipped 9 previous similar messages [ 5853.187216] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5890.819351] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 13:53:05 (1752515585) [ 5901.396771] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 5907.345367] LustreError: 276877:0:(qmt_pool.c:1295:qmt_pool_recalc()) cfs_fail_timeout id a07 sleeping for 10000ms [ 5910.505337] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5910.507730] Lustre: Skipped 1 previous similar message [ 5917.408133] LustreError: 276877:0:(qmt_pool.c:1295:qmt_pool_recalc()) cfs_fail_timeout id a07 awake [ 5917.516667] LustreError: 277027:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 5917.519066] LustreError: 277027:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 5917.622100] Lustre: server umount lustre-MDT0000 complete [ 5918.633742] LustreError: 233548:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.26@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5918.658905] LustreError: 233548:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 3 previous similar messages [ 5924.967563] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5925.093352] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5925.341781] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5925.344457] Lustre: Skipped 7 previous similar messages [ 5925.386944] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:129) [ 5925.399741] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:112 to 0x280000401:129) [ 5928.928513] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5930.495571] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 5930.508200] Lustre: Skipped 1 previous similar message [ 5953.339154] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 13:54:08 (1752515648) [ 5958.083278] LustreError: 226456:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-MDT0001: Delaying reintegration for qtype:0 until pending updates are flushed. [ 5958.096235] LustreError: 226456:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 3 previous similar messages [ 5969.955136] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 13:54:25 (1752515665) [ 5986.774883] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 13:54:41 (1752515681) [ 6006.126170] LustreError: 227946:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-OST0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 6006.132884] LustreError: 227946:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 2 previous similar messages [ 6025.985783] Lustre: *** cfs_fail_loc=a08, val=0*** [ 6025.991746] Lustre: Skipped 2527 previous similar messages [ 6026.005281] Lustre: *** cfs_fail_loc=a08, val=0*** [ 6102.795796] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 13:56:37 (1752515797) [ 6130.418390] LustreError: 226459:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:3072 soft:0 granted:3072 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 6179.939490] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 13:57:54 (1752515874) [ 6241.552419] LustreError: 226457:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1753120737 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 6387.513967] LustreError: 226456:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1753120883 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 6527.253085] LustreError: 226455:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:1000 enforced:1 hard:2048 soft:2048 granted:16385 time:1753121023 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 6626.674621] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 14:05:21 (1752516321) [ 6633.058665] Lustre: *** cfs_fail_loc=a09, val=0*** [ 6633.060655] Lustre: Skipped 1 previous similar message [ 6686.669220] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.26@tcp (stopping) [ 6686.673644] Lustre: Skipped 5 previous similar messages [ 6688.234145] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 6688.235353] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 6688.277129] LustreError: Skipped 2 previous similar messages [ 6688.278073] Lustre: Skipped 6 previous similar messages [ 6691.575198] LustreError: 287763:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 6691.586544] LustreError: 287763:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 6691.743765] LustreError: 226455:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.26@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6691.759690] Lustre: server umount lustre-MDT0000 complete [ 6691.794624] LustreError: 226455:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 5 previous similar messages [ 6699.529139] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6699.739070] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6700.062701] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6700.146608] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:131 to 0x2c0000401:161) [ 6700.146939] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:131 to 0x280000401:161) [ 6703.595182] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6705.124695] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 6705.142254] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to (at 0@lo) [ 6705.150219] Lustre: Skipped 3 previous similar messages [ 6716.816330] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 14:06:51 (1752516411) [ 6718.171295] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [ 6720.079722] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 14:06:54 (1752516414) [ 6772.463948] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 14:07:46 (1752516466) [ 6797.939478] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 14:08:12 (1752516492) [ 6826.325266] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 14:08:41 (1752516521) [ 6843.364603] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 6843.367954] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 6843.372322] Lustre: Skipped 2 previous similar messages [ 6843.378250] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6843.387047] Lustre: Skipped 6 previous similar messages [ 6853.602028] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6853.604806] Lustre: Skipped 6 previous similar messages [ 6855.136169] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 6855.214910] LustreError: 292219:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 6855.220763] LustreError: 292219:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 6855.311505] Lustre: server umount lustre-MDT0000 complete [ 6858.518171] LustreError: 226440:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752516554 with bad export cookie 2002052619570997337 [ 6858.520732] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6858.528804] LustreError: 226440:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 6858.723708] LustreError: 233548:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6858.752353] LustreError: 233548:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 10 previous similar messages [ 6864.953369] Lustre: server umount lustre-MDT0001 complete [ 6874.638043] Lustre: server umount lustre-OST0000 complete [ 6884.066316] Lustre: server umount lustre-OST0001 complete [ 6888.757621] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_hostid [ 6894.658544] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 6905.854715] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6914.253435] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6920.342245] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6925.932581] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6931.684278] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6931.770849] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6932.039423] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 6932.095225] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 6932.181557] Lustre: lustre-MDT0000: new disk, initializing [ 6932.280491] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6932.314067] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 6935.817567] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6941.864445] Lustre: DEBUG MARKER: oleg126-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6947.495315] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6947.561894] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6947.856734] Lustre: lustre-OST0000: new disk, initializing [ 6947.861818] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 6947.864743] Lustre: Skipped 1 previous similar message [ 6949.517895] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 6949.538918] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 6949.572107] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 6952.906845] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6958.992874] Lustre: DEBUG MARKER: oleg126-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6964.700907] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6964.780826] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6964.893416] Lustre: lustre-OST0001: new disk, initializing [ 6964.899801] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6964.951901] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 6964.959032] Lustre: Skipped 1 previous similar message [ 6966.341199] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 6966.350777] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 6966.380422] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 6969.958603] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6977.302272] Lustre: DEBUG MARKER: oleg126-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid [ 6988.208411] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.26@tcp (stopping) [ 6988.221390] Lustre: Skipped 4 previous similar messages [ 6991.844516] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 6991.852426] Lustre: Skipped 4 previous similar messages [ 6993.797835] LustreError: 297762:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 6993.806912] LustreError: 297762:0:(obd_class.h:479:obd_check_dev()) Skipped 25 previous similar messages [ 6993.956250] Lustre: server umount lustre-MDT0000 complete [ 7003.136805] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7003.263846] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7003.567501] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7006.726755] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7010.905173] Lustre: DEBUG MARKER: oleg126-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 7011.817965] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to (at 0@lo) [ 7011.833264] Lustre: Skipped 2 previous similar messages [ 7019.693875] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 7 sec [ 7020.054422] LustreError: 295869:0:(qsd_reint.c:618:qqi_reint_delayed()) lustre-OST0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 7020.062413] LustreError: 295869:0:(qsd_reint.c:618:qqi_reint_delayed()) Skipped 2 previous similar messages [ 7020.684442] LustreError: 298375:0:(qmt_entry.c:1166:qmt_map_lge_idx()) qmt: cannot map ostidx 1, num_used 1: rc = -22 [ 7022.002270] LustreError: 298375:0:(qmt_entry.c:1166:qmt_map_lge_idx()) qmt: cannot map ostidx 1, num_used 1: rc = -22 [ 7027.170613] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7027.179395] Lustre: Skipped 4 previous similar messages [ 7029.807460] Lustre: server umount lustre-MDT0000 complete [ 7034.989171] LustreError: 294986:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752516730 with bad export cookie 2002052619571000403 [ 7034.991083] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7035.007594] LustreError: 294986:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 7035.149393] Lustre: server umount lustre-OST0000 complete [ 7038.232244] Lustre: server umount lustre-OST0001 complete [ 7051.067409] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_hostid [ 7056.720855] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 7066.983665] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7074.659469] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7079.404343] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7084.741151] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7095.493478] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing load_modules_local [ 7103.069912] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7103.133897] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7103.316427] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 7103.341300] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 7103.410625] Lustre: lustre-MDT0000: new disk, initializing [ 7103.493581] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7103.509950] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 7106.562921] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7115.143463] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7115.198881] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7115.243212] Lustre: 303006:0:(mgs_llog.c:1345:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 7115.248594] Lustre: 303006:0:(mgs_llog.c:1345:mgs_modify_param()) Skipped 1 previous similar message [ 7115.270115] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 7115.277570] Lustre: Skipped 1 previous similar message [ 7115.329996] Lustre: lustre-MDT0001: new disk, initializing [ 7115.406186] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 7115.418483] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 7118.830506] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7122.523363] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 7127.834450] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7127.897962] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7128.126499] Lustre: lustre-OST0000: new disk, initializing [ 7128.132901] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 7129.304974] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 7129.314411] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 7129.356718] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 7133.029731] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7142.689377] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7142.763956] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7144.485931] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 7144.573596] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 7147.976380] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7157.369572] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7160.685079] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 7172.829505] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 14:14:27 (1752516867) [ 7186.829602] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 14:14:42 (1752516882) [ 7203.143586] Lustre: *** cfs_fail_loc=170c, val=0*** [ 7245.687640] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 14:15:40 (1752516940) [ 7308.257038] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 7308.262885] Lustre: Skipped 3 previous similar messages [ 7308.264914] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7308.277114] Lustre: Skipped 3 previous similar messages [ 7312.216349] LustreError: 310029:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 7312.224225] LustreError: 310029:0:(obd_class.h:479:obd_check_dev()) Skipped 17 previous similar messages [ 7312.289163] Lustre: server umount lustre-MDT0000 complete [ 7313.377583] LustreError: 303013:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7313.392830] LustreError: 303013:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 5 previous similar messages [ 7319.621476] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7319.737643] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7319.944421] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7319.948832] Lustre: Skipped 3 previous similar messages [ 7319.990921] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:33) [ 7322.704517] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7325.157585] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 7325.172950] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to (at 0@lo) [ 7325.175836] Lustre: Skipped 1 previous similar message [ 7330.284689] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 7335.783209] Lustre: server umount lustre-MDT0000 complete [ 7342.836514] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7343.242858] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:65) [ 7346.492881] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7348.203250] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 7352.518307] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 14:17:27 (1752517047) [ 7407.927862] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 14:18:22 (1752517102) [ 7463.718912] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 7331 sec ========= 14:19:18 (1752517158) [ 7465.425329] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 14:19:20 (1752517160) === [ 7468.252407] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 14:19:23 (1752517163) === [ 7476.192618] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 7476.204184] Lustre: Skipped 6 previous similar messages [ 7476.217482] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7476.224440] Lustre: Skipped 13 previous similar messages [ 7477.810489] LustreError: 314924:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 7477.837461] LustreError: 314924:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 7477.942063] Lustre: server umount lustre-MDT0000 complete [ 7481.314182] LustreError: 312246:0:(ldlm_lib.c:1113:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7481.322986] LustreError: 312246:0:(ldlm_lib.c:1113:target_handle_connect()) Skipped 13 previous similar messages [ 7485.429337] LustreError: 302998:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1752517181 with bad export cookie 2002052619571004225 [ 7485.432993] LustreError: MGC192.168.201.126@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7485.443357] LustreError: 302998:0:(ldlm_lockd.c:2550:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 7485.461758] LustreError: Skipped 1 previous similar message [ 7485.772804] Lustre: server umount lustre-MDT0001 complete [ 7502.243621] Lustre: 3606:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1752517182/real 1752517182] req@ffff99823f80aa00 x1837639682574208/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1752517198 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 7502.327207] Lustre: server umount lustre-OST0000 complete [ 7506.657142] Lustre: 3605:0:(client.c:2453:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1752517186/real 1752517186] req@ffff9982065ef100 x1837639682574464/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1752517202 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 7510.333560] Lustre: server umount lustre-OST0001 complete [ 7524.557634] Lustre: DEBUG MARKER: oleg126-server.virtnet: executing unload_modules_local [ 7527.544951] Key type lgssc unregistered [ 7527.851489] LNet: 317101:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 7528.939468] LNet: Removed LNI 192.168.201.126@tcp [ 7529.767400] Key type .llcrypt unregistered [ 7529.769793] Key type ._llcrypt unregistered