[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 849099551 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a2000-0x1465ccfff] [ 0.000000] Reserving 256MB of memory at 2528MB 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.001014] APIC: Switch to symmetric I/O mode setup [ 0.002334] x2apic enabled [ 0.003012] Switched APIC routing to physical x2apic. [ 0.004017] kvm-guest: setup PV IPIs [ 0.007000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007027] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008015] pid_max: default: 32768 minimum: 301 [ 0.009147] LSM: Security Framework initializing [ 0.011053] Yama: becoming mindful. [ 0.012040] SELinux: Initializing. [ 0.013067] *** VALIDATE selinux *** [ 0.020748] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024590] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026062] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027107] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028136] *** VALIDATE tmpfs *** [ 0.029451] *** VALIDATE proc *** [ 0.031137] *** VALIDATE cgroup *** [ 0.032011] *** VALIDATE cgroup2 *** [ 0.033253] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034154] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.036034] Spectre V2 : User space: Vulnerable [ 0.037008] Speculative Store Bypass: Vulnerable [ 0.040816] debug: unmapping init [mem 0xffffffffa6659000-0xffffffffa6660fff] [ 0.043175] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044747] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045026] ... version: 2 [ 0.046016] ... bit width: 48 [ 0.047013] ... generic registers: 4 [ 0.048014] ... value mask: 0000ffffffffffff [ 0.049014] ... max period: 00007fffffffffff [ 0.050013] ... fixed-purpose events: 3 [ 0.051013] ... event mask: 000000070000000f [ 0.052338] rcu: Hierarchical SRCU implementation. [ 0.054644] smp: Bringing up secondary CPUs ... [ 0.055574] x86: Booting SMP configuration: [ 0.056032] .... node #0, CPUs: #1 #2 #3 [ 0.068167] smp: Brought up 1 node, 4 CPUs [ 0.070014] smpboot: Max logical packages: 1 [ 0.071013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.104022] node 0 deferred pages initialised in 31ms [ 0.109168] devtmpfs: initialized [ 0.110299] x86/mm: Memory block size: 128MB [ 0.112898] gcov: version magic: 0x41383552 [ 0.114289] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.115084] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.116409] pinctrl core: initialized pinctrl subsystem [ 0.117204] [ 0.117814] ************************************************************* [ 0.118013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.119015] ** ** [ 0.120018] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.121015] ** ** [ 0.122012] ** This means that this kernel is built to expose internal ** [ 0.123013] ** IOMMU data structures, which may compromise security on ** [ 0.124013] ** your system. ** [ 0.125012] ** ** [ 0.126014] ** If you see this message and you are not debugging the ** [ 0.127015] ** kernel, report this immediately to your vendor! ** [ 0.128012] ** ** [ 0.129012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.130010] ************************************************************* [ 0.131864] NET: Registered protocol family 16 [ 0.132512] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.133070] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.134108] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.136091] cpuidle: using governor menu [ 0.137901] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.138719] PCI: Using configuration type 1 for base access [ 0.139159] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.147042] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.149021] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.152056] cryptd: max_cpu_qlen set to 1000 [ 0.154184] ACPI: Added _OSI(Module Device) [ 0.155012] ACPI: Added _OSI(Processor Device) [ 0.157014] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.158012] ACPI: Added _OSI(Processor Aggregator Device) [ 0.162570] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.170711] ACPI: Interpreter enabled [ 0.171080] ACPI: PM: (supports S0 S3 S4 S5) [ 0.172013] ACPI: Using IOAPIC for interrupt routing [ 0.173136] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.174414] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.185310] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.186058] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.187024] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.188092] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.190441] acpiphp: Slot [2] registered [ 0.191139] acpiphp: Slot [5] registered [ 0.192179] acpiphp: Slot [6] registered [ 0.193124] acpiphp: Slot [7] registered [ 0.194265] acpiphp: Slot [8] registered [ 0.195143] acpiphp: Slot [9] registered [ 0.196115] acpiphp: Slot [10] registered [ 0.197227] acpiphp: Slot [3] registered [ 0.198088] acpiphp: Slot [4] registered [ 0.199137] acpiphp: Slot [11] registered [ 0.200149] acpiphp: Slot [12] registered [ 0.201092] acpiphp: Slot [13] registered [ 0.202107] acpiphp: Slot [14] registered [ 0.203125] acpiphp: Slot [15] registered [ 0.204103] acpiphp: Slot [16] registered [ 0.205089] acpiphp: Slot [17] registered [ 0.206141] acpiphp: Slot [18] registered [ 0.207146] acpiphp: Slot [19] registered [ 0.208084] acpiphp: Slot [20] registered [ 0.209140] acpiphp: Slot [21] registered [ 0.210099] acpiphp: Slot [22] registered [ 0.211118] acpiphp: Slot [23] registered [ 0.212125] acpiphp: Slot [24] registered [ 0.213094] acpiphp: Slot [25] registered [ 0.214150] acpiphp: Slot [26] registered [ 0.215210] acpiphp: Slot [27] registered [ 0.216115] acpiphp: Slot [28] registered [ 0.217129] acpiphp: Slot [29] registered [ 0.218088] acpiphp: Slot [30] registered [ 0.219085] acpiphp: Slot [31] registered [ 0.220055] PCI host bridge to bus 0000:00 [ 0.221129] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.223031] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.225030] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.227039] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.229104] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.232062] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.234281] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.237450] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.240462] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.249807] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.256624] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.258019] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.260021] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.262019] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.264759] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.267704] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.268039] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.270835] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.275014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.286782] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.293016] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.298172] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.470020] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.476018] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.492022] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.504333] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.512020] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.518022] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.533023] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.545076] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.552017] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.557020] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.570021] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.582968] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.591021] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.596038] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.608031] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.616957] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.625018] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.630017] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.645018] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.654985] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.661018] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.666018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.683021] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.695094] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.698429] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.700387] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.702378] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.703245] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.707038] iommu: Default domain type: Passthrough [ 0.709492] SCSI subsystem initialized [ 0.712210] ACPI: bus type USB registered [ 0.713123] usbcore: registered new interface driver usbfs [ 0.716094] usbcore: registered new interface driver hub [ 0.717068] usbcore: registered new device driver usb [ 0.719161] pps_core: LinuxPPS API ver. 1 registered [ 0.720008] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.723212] PTP clock support registered [ 0.725473] EDAC MC: Ver: 3.0.0 [ 0.727154] PCI: Using ACPI for IRQ routing [ 0.729569] NetLabel: Initializing [ 0.731011] NetLabel: domain hash size = 128 [ 0.733012] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.735113] NetLabel: unlabeled traffic allowed by default [ 0.736371] vgaarb: loaded [ 0.738395] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.740018] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.748702] clocksource: Switched to clocksource kvm-clock [ 0.899413] VFS: Disk quotas dquot_6.6.0 [ 0.902296] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.908459] *** VALIDATE ramfs *** [ 0.912903] *** VALIDATE hugetlbfs *** [ 0.915969] pnp: PnP ACPI init [ 1.074968] pnp: PnP ACPI: found 6 devices [ 1.091702] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.095126] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.097330] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.099418] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.102276] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.104887] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.108184] NET: Registered protocol family 2 [ 1.110964] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.116633] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.119969] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.126472] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.129757] TCP: Hash tables configured (established 65536 bind 65536) [ 1.132804] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.135708] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.138926] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.142274] NET: Registered protocol family 1 [ 1.145797] RPC: Registered named UNIX socket transport module. [ 1.147931] RPC: Registered udp transport module. [ 1.149776] RPC: Registered tcp transport module. [ 1.151435] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.153932] NET: Registered protocol family 44 [ 1.155652] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.157662] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.159684] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.161968] PCI: CLS 0 bytes, default 64 [ 1.163724] Unpacking initramfs... [ 2.835531] debug: unmapping init [mem 0xffff8d807cc54000-0xffff8d807ffbffff] [ 2.893573] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.898260] software IO TLB: mapped [mem 0x00000000b8c54000-0x00000000bcc54000] (64MB) [ 2.911142] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.453151] Initialise system trusted keyrings [ 3.454783] Key type blacklist registered [ 3.457439] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.468996] zbud: loaded [ 3.472534] *** VALIDATE nfs *** [ 3.473518] *** VALIDATE nfs4 *** [ 3.474841] pstore: using deflate compression [ 3.480084] Platform Keyring initialized [ 3.661154] NET: Registered protocol family 38 [ 3.663184] Key type asymmetric registered [ 3.672297] Asymmetric key parser 'x509' registered [ 3.684484] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.697785] io scheduler mq-deadline registered [ 3.702104] io scheduler kyber registered [ 3.706728] io scheduler bfq registered [ 3.709555] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.713166] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.717901] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.721066] ACPI: Power Button [PWRF] [ 3.727325] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.734988] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.857394] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.866298] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.899608] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.930485] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.959563] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.964283] Non-volatile memory driver v1.3 [ 3.965885] Linux agpgart interface v0.103 [ 3.998000] virtio_blk virtio1: [vda] 146944 512-byte logical blocks (75.2 MB/71.8 MiB) [ 4.001203] vda: detected capacity change from 0 to 75235328 [ 4.089872] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 4.093448] vdb: detected capacity change from 0 to 1073741824 [ 4.305887] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.308781] vdc: detected capacity change from 0 to 2621440000 [ 4.663987] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.727611] vdd: detected capacity change from 0 to 2621440000 [ 4.796092] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.800667] vde: detected capacity change from 0 to 4294967296 [ 4.825080] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.829233] vdf: detected capacity change from 0 to 4294967296 [ 4.843750] libphy: Fixed MDIO Bus: probed [ 4.867511] usbcore: registered new interface driver usbserial_generic [ 4.872057] usbserial: USB Serial support registered for generic [ 4.875746] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 5.023641] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 5.029668] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 5.051932] mousedev: PS/2 mouse device common for all mice [ 5.393776] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 5.406945] rtc_cmos 00:05: RTC can wake from S4 [ 5.410581] rtc_cmos 00:05: registered as rtc0 [ 5.410662] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 5.411240] intel_pstate: CPU model not supported [ 5.558511] hpet1: lost 8 rtc interrupts [ 5.562579] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 5.574969] hid: raw HID events driver (C) Jiri Kosina [ 5.580846] usbcore: registered new interface driver usbhid [ 5.581962] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 5.583247] usbhid: USB HID core driver [ 5.583631] drop_monitor: Initializing network drop monitor service [ 5.650615] Initializing XFRM netlink socket [ 5.660190] NET: Registered protocol family 10 [ 5.667419] Segment Routing with IPv6 [ 5.672333] NET: Registered protocol family 17 [ 5.678495] mpls_gso: MPLS GSO support [ 5.789406] RAS: Correctable Errors collector initialized. [ 5.794809] AVX version of gcm_enc/dec engaged. [ 5.826967] AES CTR mode by8 optimization enabled [ 6.044263] sched_clock: Marking stable (6044020156, 0)->(7226685281, -1182665125) [ 6.049406] registered taskstats version 1 [ 6.052416] Loading compiled-in X.509 certificates [ 6.055058] zswap: loaded using pool lzo/zbud [ 6.090248] Key type big_key registered [ 6.108224] Key type encrypted registered [ 6.110524] ima: No TPM chip found, activating TPM-bypass! [ 6.113211] ima: Allocated hash algorithm: sha1 [ 6.115629] ima: No architecture policies found [ 6.118111] evm: Initialising EVM extended attributes: [ 6.121098] evm: security.selinux [ 6.122522] evm: security.ima [ 6.123841] evm: security.capability [ 6.125812] evm: HMAC attrs: 0x1 [ 6.129946] rtc_cmos 00:05: setting system clock to 2026-08-27 14:32:07 UTC (1787841127) [ 6.139422] debug: unmapping init [mem 0xffffffffa7603000-0xffffffffa77fffff] [ 6.143889] debug: unmapping init [mem 0xffffffffa6382000-0xffffffffa6658fff] [ 6.154142] Write protecting the kernel read-only data: 28672k [ 6.161567] debug: unmapping init [mem 0xffffffffa4a03000-0xffffffffa4bfffff] [ 6.166602] debug: unmapping init [mem 0xffffffffa5314000-0xffffffffa53fffff] [ 6.227210] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 6.239265] systemd[1]: Detected virtualization kvm. [ 6.241535] systemd[1]: Detected architecture x86-64. [ 6.244372] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 6.276199] systemd[1]: No hostname configured. [ 6.279500] systemd[1]: Set hostname to . [ 6.291746] random: systemd: uninitialized urandom read (16 bytes read) [ 6.296640] systemd[1]: Initializing machine ID from random generator. [ 6.413467] random: ln: uninitialized urandom read (6 bytes read) [ 6.540398] random: systemd: uninitialized urandom read (16 bytes read) [ 6.543603] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ 6.548866] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 6.556788] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ OK ] Reached target Swap. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Local File Systems. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... [ OK ] Started Memstrack Anylazing Service. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... Starting Setup Virtual Console... Starting Journal Service... [ OK ] Reached target Paths. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ 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. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 7.961717] device-mapper: uevent: version 1.0.3 [ 7.964171] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 9.041845] random: fast init done [ 9.233603] virtio_net virtio0 ens2: renamed from eth0 [ 9.241635] scsi host0: ata_piix [ 9.406722] scsi host1: ata_piix [ 9.409779] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 9.414943] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 13.682316] random: crng init done [ 13.685171] random: 7 urandom warning(s) missed due to ratelimiting [ 16.875394] dracut-initqueue[594]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 18.206393] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 19.878806] printk: systemd: 26 output lines suppressed due to ratelimiting [ 20.328629] SELinux: Disabled at runtime. [ 20.405510] 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) [ 20.415162] systemd[1]: Detected virtualization kvm. [ 20.417751] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 23.247938] systemd[1]: initrd-switch-root.service: Succeeded. [ 23.255300] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 23.280753] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 23.288015] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 23.301990] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 23.329406] systemd[1]: Starting Journal Service... Starting Journal Service... [ 23.376889] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice system-sshd\x2dkeygen.slice. Activating swap /dev/disk/by-label/SWAP... Mounting Kernel Debug File System... [ OK ] Stopped target Switch Root. [ OK ] Created slice system-getty.slice. [ OK ] Listening on initctl Compatibility Named Pipe. [ 23.638771] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on udev Control Socket. Mounting Huge Pages File System... [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice User and Session Slice. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Remount Root and Kernel File Systems... [ OK ] Listening on Process Core Dump Socket. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... Starting udev Coldplug all Devices... Mounting POSIX Message Queue File System... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Reached target Slices. [ OK ] Stopped target Initrd Root 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 ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted 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 udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 25.617575] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 26.837584] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 27.086524] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 28.098455] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 28.205586] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit) [** ] A start job is running for Configur…-only root support (9s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ ***] A start job is running for Configur…only root support (11s / no limit)[ 34.633213] Key type dns_resolver registered [ **] A start job is running for Configur…only root support (11s / no limit) [ *] A start job is running for Configur…only root support (12s / no limit) [ **] A start job is running for Configur…only root support (12s / no limit) [ ***] A start job is running for Configur…only root support (13s / no limit)[ 36.205051] NFS: Registering the id_resolver key type [ 36.235658] Key type id_resolver registered [ 36.270707] Key type id_legacy registered [ *** ] A start job is running for Configur…only root support (13s / no limit) [ *** ] A start job is running for Configur…only root support (14s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ 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... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started Login Service. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg142-server login: [ 65.958941] hrtimer: interrupt took 13932011 ns [ 107.650205] libcfs: loading out-of-tree module taints kernel. [ 107.686847] Key type ._llcrypt registered [ 107.688906] Key type .llcrypt registered [ 107.774835] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_hostid [ 132.588643] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 134.475910] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 134.490741] alg: No test for adler32 (adler32-zlib) [ 136.077304] Lustre: Lustre: Build Version: 2.17.57_96_g86a8d2f [ 136.901823] LNet: Added LNI 192.168.201.142@tcp [8/256/0/180] [ 138.865548] Key type lgssc registered [ 141.309513] Lustre: Echo OBD driver; http://www.lustre.org/ [ 163.768987] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 211.973595] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 225.966388] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 226.013453] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 227.470549] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 227.552500] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 227.707236] Lustre: lustre-MDT0000: new disk, initializing [ 227.770845] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 227.785380] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 232.355393] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 246.564529] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 246.697157] Lustre: 6521:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 246.750178] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 246.756550] Lustre: Skipped 1 previous similar message [ 246.876370] Lustre: lustre-MDT0001: new disk, initializing [ 246.973474] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 247.018975] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 247.039315] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 251.440638] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 256.486980] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 266.742092] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 267.150441] Lustre: lustre-OST0000: new disk, initializing [ 267.154434] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 267.159235] Lustre: 8460:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 267.220091] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 268.850110] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 268.858571] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 268.974066] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 274.252964] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 287.622156] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 287.727750] Lustre: lustre-OST0001: new disk, initializing [ 287.735603] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 287.740319] Lustre: 9534:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 287.791753] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 293.756786] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 297.518137] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 297.530404] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 297.584624] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 307.718179] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 317.944719] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 328.109980] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing check_logdir /tmp/testlogs/ [ 334.080769] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing yml_node [ 339.804983] Lustre: DEBUG MARKER: Client: 2.17.57.96 [ 343.082470] Lustre: DEBUG MARKER: MDS: 2.17.57.96 [ 346.273378] Lustre: DEBUG MARKER: OSS: 2.17.57.96 [ 348.951398] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Thu Aug 27 10:37:47 EDT 2026 [ 370.761895] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 373.012978] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 [ 376.771450] Lustre: DEBUG MARKER: === sanity-quota: start setup 10:38:16 (1787841496) === [ 384.880251] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing check_config_client /mnt/lustre [ 403.503190] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 407.401770] Lustre: 13443:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 413.681068] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 424.207380] Lustre: DEBUG MARKER: === sanity-quota: finish setup 10:39:02 (1787841542) === [ 492.548607] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 10:40:12 (1787841612) [ 537.306910] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 10:40:56 (1787841656) [ 551.054077] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 557.391684] Lustre: DEBUG MARKER: Write... [ 560.589603] Lustre: DEBUG MARKER: Write out of block quota ... [ 600.721486] Lustre: DEBUG MARKER: -------------------------------------- [ 603.317212] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 612.514506] Lustre: DEBUG MARKER: Write... [ 615.618144] Lustre: DEBUG MARKER: Write out of block quota ... [ 654.608648] Lustre: DEBUG MARKER: -------------------------------------- [ 656.279416] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 659.173725] Lustre: DEBUG MARKER: Write... [ 661.668617] Lustre: DEBUG MARKER: Write out of block quota ... [ 714.831424] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 10:43:54 (1787841834) [ 729.587471] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 753.520666] Lustre: DEBUG MARKER: Write... [ 755.940689] Lustre: DEBUG MARKER: Write out of block quota ... [ 790.348580] Lustre: DEBUG MARKER: -------------------------------------- [ 792.393372] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 801.219646] Lustre: DEBUG MARKER: Write... [ 803.914974] Lustre: DEBUG MARKER: Write out of block quota ... [ 843.522052] Lustre: DEBUG MARKER: -------------------------------------- [ 845.386958] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 848.618570] Lustre: DEBUG MARKER: Write... [ 850.991484] Lustre: DEBUG MARKER: Write out of block quota ... [ 912.179109] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 10:47:11 (1787842031) [ 922.888604] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 952.872731] Lustre: DEBUG MARKER: Write... [ 956.092421] Lustre: DEBUG MARKER: Write out of block quota ... [ 1045.907780] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 10:49:25 (1787842165) [ 1060.024865] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 1087.364859] Lustre: DEBUG MARKER: Write... [ 1089.645385] Lustre: DEBUG MARKER: Write out of block quota ... [ 1176.230703] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 10:51:36 (1787842296) [ 1188.765955] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 1202.809667] Lustre: DEBUG MARKER: Write... [ 1205.377326] Lustre: DEBUG MARKER: Write out of block quota ... [ 1219.106926] Lustre: DEBUG MARKER: Write... [ 1276.700803] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 10:53:16 (1787842396) [ 1289.575352] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1304.776502] Lustre: DEBUG MARKER: Write... [ 1307.294267] Lustre: DEBUG MARKER: Write out of block quota ... [ 1349.108845] Lustre: DEBUG MARKER: Write... [ 1352.759089] Lustre: DEBUG MARKER: Write out of block quota ... [ 1407.742814] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 10:55:27 (1787842527) [ 1418.775810] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 1433.099439] Lustre: 9033:0:(osd_handler.c:2191:osd_trans_start()) lustre-MDT0000: credits 6570 > trans_max 3200 [ 1433.104297] Lustre: 9033:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 4/16/0, destroy: 0/0/0 [ 1433.108530] Lustre: 9033:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 401/401/0, xattr_set: 602/5615/0 [ 1433.112817] Lustre: 9033:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 20/142/0, punch: 0/0/0, quota 8/328/0 [ 1433.118397] Lustre: 9033:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/68/0, delete: 0/0/0 [ 1433.122245] Lustre: 9033:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1433.125876] CPU: 2 PID: 9033 Comm: mdt00_003 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [ 1433.131225] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 1433.134310] Call Trace: [ 1433.137044] ? dump_stack+0xbb/0x10e [ 1433.138701] ? osd_trans_start+0x8db/0x9d0 [osd_ldiskfs] [ 1433.141049] ? dt_trans_start+0x1c/0x70 [obdclass] [ 1433.143244] ? top_trans_start+0x4fd/0xd00 [ptlrpc] [ 1433.145570] ? lod_xattr_list+0x30/0x30 [lod] [ 1433.147486] ? lod_trans_start+0x109/0x4c0 [lod] [ 1433.149476] ? mdd_declare_attr_set+0x91/0x880 [mdd] [ 1433.151593] ? mdd_env_info+0x25/0xc0 [mdd] [ 1433.153401] ? mdd_trans_start+0x18/0x30 [mdd] [ 1433.155798] ? mdd_attr_set+0xa5a/0x1330 [mdd] [ 1433.157811] ? mdt_reint_setattr+0x14aa/0x2030 [mdt] [ 1433.159782] ? mdt_reint_setattr+0x14aa/0x2030 [mdt] [ 1433.162358] ? mdt_reint_rec+0x139/0x2b0 [mdt] [ 1433.164929] ? mdt_reint_internal+0x693/0xdc0 [mdt] [ 1433.167566] ? mdt_reint+0x163/0x190 [mdt] [ 1433.169002] ? tgt_handle_request0+0x137/0xaf0 [ptlrpc] [ 1433.173962] ? tgt_request_handle+0x575/0x1f70 [ptlrpc] [ 1433.176443] ? ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [ 1433.179166] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [ 1433.183394] ? ptlrpc_main+0xce8/0x1400 [ptlrpc] [ 1433.186047] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [ 1433.190454] ? kthread+0x1d1/0x200 [ 1433.193619] ? set_kthread_struct+0x70/0x70 [ 1433.201261] ? ret_from_fork+0x1f/0x30 [ 1434.867559] Lustre: DEBUG MARKER: Write... [ 1446.261312] Lustre: DEBUG MARKER: Write out of block quota ... [ 1514.297690] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 10:57:14 (1787842634) [ 1527.516544] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 1534.893485] Lustre: DEBUG MARKER: Write 5MiB Using Fallocate [ 1543.847385] Lustre: DEBUG MARKER: Write 11MiB Using Fallocate [ 1622.848627] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 10:59:02 (1787842742) [ 1636.425402] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1651.570820] Lustre: DEBUG MARKER: Write... [ 1653.879780] Lustre: DEBUG MARKER: Write out of block quota ... [ 1684.867699] Lustre: DEBUG MARKER: Write... [ 1687.376730] Lustre: DEBUG MARKER: Write out of block quota ... [ 1697.965676] LustreError: 6529:0:(qmt_entry.c:558: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 [ 1738.956489] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 11:00:58 (1787842858) [ 1756.556565] Lustre: DEBUG MARKER: -------------------------------------- [ 1758.174672] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 2079.015280] Lustre: DEBUG MARKER: == sanity-quota test 1k: LQA: Block hard limit (normal use and out of quota) ========================================================== 11:06:38 (1787843198) [ 2092.516719] Lustre: DEBUG MARKER: Write... [ 2095.339290] Lustre: DEBUG MARKER: Write out of block quota ... [ 2129.253559] Lustre: DEBUG MARKER: Write... [ 2133.409230] Lustre: DEBUG MARKER: Write out of block quota ... [ 2162.947785] Lustre: DEBUG MARKER: Write... [ 2165.584379] Lustre: DEBUG MARKER: Write out of block quota ... [ 2206.738319] Lustre: DEBUG MARKER: == sanity-quota test 1l: Async writes should not be rejected by quota with root_prj_enable ========================================================== 11:08:46 (1787843326) [ 2254.971773] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 2256.872728] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 11:09:36 (1787843376) [ 2301.392562] Lustre: DEBUG MARKER: Write after timer goes off [ 2303.759931] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2381.673330] Lustre: DEBUG MARKER: Write after timer goes off [ 2383.448564] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2455.147439] Lustre: DEBUG MARKER: Write after timer goes off [ 2458.275878] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2532.061593] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 11:14:12 (1787843652) [ 2583.998761] Lustre: DEBUG MARKER: Write after timer goes off [ 2586.966773] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2658.740465] Lustre: DEBUG MARKER: Write after timer goes off [ 2661.284870] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2731.762168] Lustre: DEBUG MARKER: Write after timer goes off [ 2734.755966] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2818.026142] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 11:18:57 (1787843937) [ 2882.874295] Lustre: DEBUG MARKER: Write after timer goes off [ 2884.590735] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2959.644944] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 2961.827797] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 11:21:21 (1787844081) [ 2973.027354] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 3080.257674] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 11:23:19 (1787844199) [ 3122.055788] Lustre: *** cfs_fail_loc=513, val=601*** [ 3122.062614] Lustre: Skipped 3 previous similar messages [ 3123.411199] Lustre: *** cfs_fail_loc=513, val=601*** [ 3123.801742] LustreError: 16583:0:(service.c:2341:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1874687438017408 [ 3124.704922] Lustre: *** cfs_fail_loc=513, val=601*** [ 3124.714100] Lustre: Skipped 30 previous similar messages [ 3127.177046] Lustre: *** cfs_fail_loc=513, val=601*** [ 3127.183953] Lustre: Skipped 6 previous similar messages [ 3131.361187] Lustre: *** cfs_fail_loc=513, val=601*** [ 3131.363095] Lustre: Skipped 17 previous similar messages [ 3138.528946] LustreError: 16583:0:(service.c:2341:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1874687438024192 [ 3138.544213] LustreError: 16583:0:(service.c:2341:ptlrpc_server_handle_req_in()) Skipped 2 previous similar messages [ 3139.040289] Lustre: 8449:0:(service.c:1612:ptlrpc_at_send_early_reply()) @@@ Could not add any time (5/5), not sending early reply req@ffff8d80e02eb480 x1874687416972544/t0(0) o4->842ecf9f-0625-454f-9d51-e3d255aca8ab@192.168.201.42@tcp:490/0 lens 488/448 e 1 to 0 dl 1787844265 ref 2 fl Interpret:/600/0 rc 0/0 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 3139.563179] Lustre: *** cfs_fail_loc=513, val=601*** [ 3139.573918] Lustre: Skipped 30 previous similar messages [ 3140.065864] Lustre: 19466:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787844245/real 1787844245] req@ffff8d80ff733c00 x1874687438017408/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1787844261 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 3140.100590] 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 [ 3140.129472] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3140.147959] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3140.199606] LustreError: 16585:0:(service.c:2341:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1874687438027136 [ 3153.888407] Lustre: 3654:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787844259/real 1787844259] req@ffff8d80eeb312c0 x1874687438024448/t0(0) o601->lustre-MDT0000-lwp-MDT0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1787844275 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [ 3153.933105] 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 [ 3153.945306] Lustre: lustre-MDT0000: Received new LWP connection from 0@lo, keep former export from same NID [ 3153.969407] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3154.953162] Lustre: 3655:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787844259/real 1787844259] req@ffff8d80eeb31a40 x1874687438024320/t0(0) o601->lustre-MDT0000-lwp-MDT0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1787844275 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [ 3156.000321] 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 [ 3156.036882] Lustre: *** cfs_fail_loc=513, val=601*** [ 3156.038867] Lustre: Skipped 89 previous similar messages [ 3156.063533] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3156.103499] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3159.010405] LustreError: 6532:0:(service.c:2341:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1874687438036864 [ 3159.027128] LustreError: 6532:0:(service.c:2341:ptlrpc_server_handle_req_in()) Skipped 5 previous similar messages [ 3175.376208] Lustre: 3656:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787844280/real 1787844280] req@ffff8d7fcab11a40 x1874687438037248/t0(0) o601->lustre-MDT0000-lwp-MDT0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1787844296 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [ 3175.392405] 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 [ 3175.416619] Lustre: 3656:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 3175.439856] Lustre: Skipped 1 previous similar message [ 3175.458906] Lustre: lustre-MDT0000: Received new LWP connection from 0@lo, keep former export from same NID [ 3175.459849] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3175.468373] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3175.484571] Lustre: Skipped 1 previous similar message [ 3206.433909] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 11:25:26 (1787844326) [ 3236.466694] Lustre: Failing over lustre-OST0000 [ 3236.734643] Lustre: server umount lustre-OST0000 complete [ 3236.839036] 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 [ 3236.872481] Lustre: Skipped 2 previous similar messages [ 3241.956264] LustreError: 42173:0:(ldlm_lib.c:1228: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. [ 3241.978615] LustreError: 42173:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 5 previous similar messages [ 3244.947023] LustreError: 16994:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3247.087376] LustreError: 42121:0:(ldlm_lib.c:1228: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. [ 3247.104145] LustreError: 42121:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 1 previous similar message [ 3250.072330] LustreError: 16994:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3251.211599] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3251.673807] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3251.718036] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3253.600423] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3253.698091] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3253.706831] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3253.732343] Lustre: Skipped 2 previous similar messages [ 3258.548890] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3269.355338] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3276.733741] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3283.397924] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3289.918692] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3296.730703] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3303.337429] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3323.859127] Lustre: Failing over lustre-OST0000 [ 3323.930249] Lustre: server umount lustre-OST0000 complete [ 3325.408881] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 3325.413286] 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 [ 3325.435648] Lustre: Skipped 1 previous similar message [ 3325.440554] LustreError: 8445:0:(ldlm_lib.c:1228: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. [ 3325.476358] LustreError: 8445:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 1 previous similar message [ 3332.353888] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3332.820855] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3332.853694] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3333.936193] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3334.864232] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3334.868412] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3334.892418] Lustre: Skipped 1 previous similar message [ 3339.377911] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3346.806703] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3353.518332] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3358.994326] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3364.575890] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3372.269216] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3380.176589] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3411.684425] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 11:28:51 (1787844531) [ 3445.461397] Lustre: *** cfs_fail_loc=a02, val=0*** [ 3452.828852] Lustre: Failing over lustre-OST0000 [ 3452.890320] Lustre: server umount lustre-OST0000 complete [ 3452.904787] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 3452.906975] 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 [ 3452.937513] LustreError: Skipped 2 previous similar messages [ 3452.941615] LustreError: 8445:0:(ldlm_lib.c:1228: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. [ 3452.959858] LustreError: 8445:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 5 previous similar messages [ 3462.004563] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3462.355195] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3462.384083] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3463.669625] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3463.856457] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3463.857164] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3463.891027] Lustre: Skipped 1 previous similar message [ 3469.098155] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3478.031564] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3484.766994] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3490.761824] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3497.265109] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3504.298994] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3510.762265] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3554.883528] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 11:31:14 (1787844674) [ 3579.834295] LustreError: 98242:0:(qsd_reint.c:488:qsd_reint_main()) cfs_fail_timeout id a03 sleeping for 10000ms [ 3582.056966] Lustre: Failing over lustre-MDT0000 [ 3582.905466] LustreError: 55549:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3582.923379] LustreError: 55549:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 6 previous similar messages [ 3582.944698] Lustre: server umount lustre-MDT0000 complete [ 3585.506400] 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 [ 3585.536474] Lustre: Skipped 3 previous similar messages [ 3587.305869] LustreError: 98245:0:(qsd_reint.c:488:qsd_reint_main()) cfs_fail_timeout interrupted [ 3594.739423] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3594.876272] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3595.317675] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3595.380664] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3598.241176] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3599.838173] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3600.377369] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3600.385576] Lustre: Skipped 1 previous similar message [ 3600.399256] LustreError: 3652:0:(ldlm_resource.c:1207:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x2020000:0x0].0x0 (ffff8d80c2f2c000) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 3600.512694] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 3600.513559] Lustre: 98247:0:(qsd_reint.c:249:qsd_reint_index()) lustre-OST0001: index version for fid [0x200000005:0x100c:0x0] is 0, but index isn't empty (1) [ 3600.608397] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:99 to 0x2c0000401:129) [ 3600.609801] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:165 to 0x280000401:193) [ 3607.795643] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3702.231426] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3709.923586] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3716.892917] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3724.821425] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3734.253759] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3773.064488] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 11:34:52 (1787844892) [ 3796.287959] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3803.445778] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3848.304510] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 11:36:08 (1787844968) [ 3878.249382] Lustre: Failing over lustre-MDT0001 [ 3879.028834] Lustre: server umount lustre-MDT0001 complete [ 3879.856964] LustreError: 6528:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3879.891702] LustreError: 6528:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 10 previous similar messages [ 3881.956074] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3881.957044] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3881.978413] Lustre: Skipped 1 previous similar message [ 3892.621478] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3893.234695] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3893.297323] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3894.376234] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3898.353242] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3898.355656] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3898.363089] Lustre: Skipped 3 previous similar messages [ 3898.440331] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 3898.521620] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:33) [ 3907.886818] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3915.187059] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3922.897360] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3932.408634] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3943.471847] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3953.656547] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4032.106213] Lustre: Failing over lustre-MDT0001 [ 4032.445603] LustreError: 10024:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4032.469260] LustreError: 10024:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 11 previous similar messages [ 4032.506220] Lustre: server umount lustre-MDT0001 complete [ 4036.577178] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 4036.579293] 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 [ 4036.615354] Lustre: Skipped 4 previous similar messages [ 4042.866971] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4043.705845] Lustre: lustre-MDT0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4043.787146] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4045.149462] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4048.870264] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4048.875328] Lustre: Skipped 2 previous similar messages [ 4048.905478] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 4048.972484] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:65) [ 4049.167189] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4057.974739] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4064.315556] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4069.898677] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4076.547725] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4082.615569] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4089.934792] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4169.753352] Lustre: DEBUG MARKER: == sanity-quota test 7f: Quota reintegration automatically ========================================================== 11:41:29 (1787845289) [ 4183.927439] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4183.943455] Lustre: Skipped 3 previous similar messages [ 4190.759682] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4190.761748] LustreError: 42383:0:(qsd_reint.c:633:qqi_reint_delayed()) lustre-OST0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 4244.452185] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4244.513204] Lustre: 114713:0:(qsd_reint.c:249:qsd_reint_index()) lustre-MDT0001: index version for fid [0x200000005:0x1004:0x0] is 0, but index isn't empty (1) [ 4282.773097] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 11:43:22 (1787845402) [ 4474.497194] Lustre: DEBUG MARKER: == sanity-quota test 9: Block limit larger than 4GB (b10707) ========================================================== 11:46:34 (1787845594) [ 4476.389152] Lustre: DEBUG MARKER: OST0_SIZE: 3605152 required: 4900000 [ 4483.175855] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 11:46:43 (1787845603) [ 4527.870783] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 11:47:27 (1787845647) [ 4569.819890] Lustre: DEBUG MARKER: == sanity-quota test 12a: Block quota rebalancing ======== 11:48:09 (1787845689) [ 4643.601503] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 11:49:22 (1787845762) [ 4773.457198] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 11:51:33 (1787845893) [ 4832.173408] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 11:52:32 (1787845952) [ 4855.591364] Lustre: Failing over lustre-OST0000 [ 4855.727199] Lustre: server umount lustre-OST0000 complete [ 4856.781636] LustreError: 116287:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4856.800767] LustreError: 116287:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 8 previous similar messages [ 4857.826434] 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 [ 4869.562347] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4869.995390] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4870.051060] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4871.139578] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 4872.006192] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 4872.006207] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4872.027495] Lustre: Skipped 2 previous similar messages [ 4876.946774] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4912.743173] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 11:53:52 (1787846032) [ 4941.910813] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 11:54:21 (1787846061) [ 4963.490267] Lustre: lustre-MDT0001: Client 842ecf9f-0625-454f-9d51-e3d255aca8ab (at 192.168.201.42@tcp) reconnecting [ 4983.729359] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 11:55:03 (1787846103) [ 4985.764114] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 4987.956599] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 11:55:07 (1787846107) [ 5011.721525] Lustre: *** cfs_fail_loc=a04, val=37*** [ 5011.724928] LustreError: 8449:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr lqe: ffff8d80ed853980 id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 5012.841071] Lustre: *** cfs_fail_loc=a04, val=37*** [ 5012.844311] LustreError: 116267:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr lqe: ffff8d80ed853980 id:60000 enforced:1 granted: 0 pending:0 waiting:1056 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 5014.945805] Lustre: *** cfs_fail_loc=a04, val=37*** [ 5014.949454] LustreError: 116269:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr lqe: ffff8d80ed853980 id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 5073.224834] Lustre: *** cfs_fail_loc=a04, val=11*** [ 5131.917534] Lustre: *** cfs_fail_loc=a04, val=110*** [ 5131.929256] Lustre: Skipped 2 previous similar messages [ 5189.469937] Lustre: *** cfs_fail_loc=a04, val=107*** [ 5189.477626] Lustre: Skipped 2 previous similar messages [ 5278.909758] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 11:59:58 (1787846398) [ 5293.621592] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5300.169551] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 5309.348961] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5311.362730] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5314.251000] Lustre: Failing over lustre-MDT0000 [ 5314.906135] LustreError: 6530:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5314.924419] LustreError: 6530:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 8 previous similar messages [ 5315.087146] Lustre: server umount lustre-MDT0000 complete [ 5331.937131] Lustre: 3653:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787846436/real 1787846436] req@ffff8d7fc8bd1680 x1874687440515584/t0(0) o400->MGC192.168.201.142@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1787846452 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5331.953947] Lustre: 3653:0:(client.c:2503:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 5331.959925] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5340.538551] LDISKFS-fs (dm-0): 7 truncates cleaned up [ 5340.540449] LDISKFS-fs (dm-0): recovery complete [ 5340.555910] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5341.856616] LustreError: 140963:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 5341.864654] LustreError: 140963:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8d80f64f8f00 x1874687440521472/t0(0) o250->MGC192.168.201.142@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1787846463 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5341.893396] LustreError: 140963:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 5342.195204] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x45ed4a39fd9cbd67 [ 5342.627090] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5342.673945] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5344.495694] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5347.951357] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 5348.024539] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:676 to 0x280000401:705) [ 5348.024742] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:608 to 0x2c0000401:641) [ 5348.728658] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5359.303830] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5361.100413] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5366.988318] Lustre: DEBUG MARKER: (dd_pid=127590, time=0, timeout=600) [ 5395.655889] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5401.945984] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 5410.712543] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5412.631321] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5414.783255] Lustre: Failing over lustre-MDT0000 [ 5414.900595] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5414.912379] 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 [ 5414.931674] Lustre: Skipped 5 previous similar messages [ 5414.942329] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5415.159643] Lustre: server umount lustre-MDT0000 complete [ 5415.923629] LustreError: lustre-MDT0000-lwp-OST0001: operation ldlm_enqueue to node 0@lo failed: rc = -107 [ 5415.931828] LustreError: Skipped 1 previous similar message [ 5415.932819] LustreError: 6529:0:(ldlm_lib.c:1228: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. [ 5415.955869] LustreError: 6529:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 35 previous similar messages [ 5435.872178] Lustre: 3656:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787846540/real 1787846540] req@ffff8d80ed708b40 x1874687440583040/t0(0) o400->MGC192.168.201.142@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1787846556 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5435.921719] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5439.300425] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 5439.306781] LDISKFS-fs (dm-0): recovery complete [ 5439.322457] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5446.557743] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5446.635753] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5448.585098] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5451.783067] LustreError: 3652:0:(ldlm_resource.c:1207:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x20000:0x0].0x0 (ffff8d80c3d56100) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 5451.792192] LustreError: 3652:0:(ldlm_resource.c:1207:ldlm_resource_complain()) Skipped 5 previous similar messages [ 5451.811224] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5451.816790] Lustre: Skipped 6 previous similar messages [ 5451.854820] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 5451.900361] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:707 to 0x280000401:737) [ 5451.903163] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:608 to 0x2c0000401:673) [ 5452.514163] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5464.656380] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5466.866932] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5473.990348] Lustre: DEBUG MARKER: (dd_pid=129989, time=0, timeout=600) [ 5515.400826] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 12:03:55 (1787846635) [ 5566.988295] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 12:04:46 (1787846686) [ 5600.229024] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 5614.496800] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 5616.883700] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 5618.704645] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 5621.662141] Lustre: DEBUG MARKER: Set quota for 1 times [ 5625.182983] Lustre: DEBUG MARKER: Set quota for 2 times [ 5629.420590] Lustre: DEBUG MARKER: Set quota for 3 times [ 5633.358343] Lustre: DEBUG MARKER: Set quota for 4 times [ 5637.011323] Lustre: DEBUG MARKER: Set quota for 5 times [ 5641.286654] Lustre: DEBUG MARKER: Set quota for 6 times [ 5645.544400] Lustre: DEBUG MARKER: Set quota for 7 times [ 5649.209445] Lustre: DEBUG MARKER: Set quota for 8 times [ 5698.386447] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 12:06:58 (1787846818) [ 5712.866917] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5712.876222] Lustre: Skipped 3 previous similar messages [ 5717.985895] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5717.989612] Lustre: Skipped 3 previous similar messages [ 5719.053760] Lustre: server umount lustre-MDT0000 complete [ 5722.994816] LustreError: 6515:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787846844 with bad export cookie 5038765171025954784 [ 5722.995790] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5723.006455] LustreError: 6515:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 5723.105968] LustreError: 10024:0:(ldlm_lib.c:1228: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. [ 5723.117564] LustreError: 10024:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 37 previous similar messages [ 5723.123533] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5723.318919] Lustre: server umount lustre-MDT0001 complete [ 5729.964813] Lustre: server umount lustre-OST0000 complete [ 5734.087666] Lustre: server umount lustre-OST0001 complete [ 5754.042714] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 5765.307031] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5765.957444] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5770.581763] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5781.224024] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5781.473668] Lustre: lustre-MDT0001: Not available for connect from 0@lo (not set up) [ 5781.480465] Lustre: Skipped 1 previous similar message [ 5781.771063] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5786.964763] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5789.966824] Lustre: 153899:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5797.109059] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5797.406361] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5804.184636] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5807.665890] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:97) [ 5810.730996] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:739 to 0x280000401:769) [ 5812.988170] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5813.291669] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5818.352312] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:676 to 0x2c0000401:705) [ 5821.084577] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5829.556127] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5834.057082] Lustre: 155775:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5853.666349] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5853.681559] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5859.651499] Lustre: server umount lustre-MDT0000 complete [ 5864.192208] LustreError: 152727:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787846985 with bad export cookie 5038765171025961630 [ 5864.196828] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5864.208845] LustreError: 152727:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 5864.419222] LustreError: 156476:0:(ldlm_lib.c:1228: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. [ 5864.439482] LustreError: 156476:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 9 previous similar messages [ 5864.523970] Lustre: server umount lustre-MDT0001 complete [ 5871.701723] Lustre: server umount lustre-OST0000 complete [ 5876.843598] Lustre: server umount lustre-OST0001 complete [ 5893.306655] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 5904.229976] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5904.669124] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5909.625537] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5917.758840] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5923.508202] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5927.016644] Lustre: 159514:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5937.565254] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5938.178901] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5938.182915] Lustre: Skipped 1 previous similar message [ 5943.343533] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:129) [ 5946.287593] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5949.418624] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:739 to 0x280000401:801) [ 5956.798208] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5962.738504] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:676 to 0x2c0000401:737) [ 5965.911510] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5975.996725] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5980.977622] Lustre: 161389:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5993.603623] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 12:11:53 (1787847113) [ 5995.385573] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 6144 [ 5997.481806] Lustre: DEBUG MARKER: run for 4MB test file [ 6009.823557] Lustre: DEBUG MARKER: User quota (limit: 4 MB) [ 6016.850749] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 6018.904722] Lustre: DEBUG MARKER: Write half of file [ 6020.951145] Lustre: DEBUG MARKER: Write out of block quota ... [ 6022.827229] Lustre: DEBUG MARKER: Step1: done [ 6024.412824] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 6026.619118] Lustre: DEBUG MARKER: Step2: done [ 6053.730698] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 61440 [ 6055.123394] Lustre: DEBUG MARKER: run for 40MB test file [ 6066.777281] Lustre: DEBUG MARKER: User quota (limit: 40 MB) [ 6072.159671] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 6073.819669] Lustre: DEBUG MARKER: Write half of file [ 6076.460306] Lustre: DEBUG MARKER: Write out of block quota ... [ 6079.468773] Lustre: DEBUG MARKER: Step1: done [ 6081.008192] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 6082.833596] Lustre: DEBUG MARKER: Step2: done [ 6131.347664] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 12:14:11 (1787847251) [ 6180.281943] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 12:15:00 (1787847300) [ 6217.779132] Lustre: DEBUG MARKER: Write... [ 6220.167956] Lustre: DEBUG MARKER: Write out of block quota ... [ 6283.037849] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 12:16:42 (1787847402) [ 6289.579317] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 12:16:49 (1787847409) [ 6299.003948] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 12:16:58 (1787847418) [ 6307.195861] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 12:17:07 (1787847427) [ 6314.880125] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 12:17:14 (1787847434) [ 6361.342844] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 6497.350611] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 6629.813822] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 12:22:29 (1787847749) [ 6679.218339] Lustre: DEBUG MARKER: Restart... [ 6684.658504] 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 [ 6684.661181] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6684.692535] Lustre: Skipped 18 previous similar messages [ 6684.709602] Lustre: Skipped 11 previous similar messages [ 6689.634151] Lustre: server umount lustre-MDT0000 complete [ 6689.770562] LustreError: 158369:0:(ldlm_lib.c:1228: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. [ 6689.806851] LustreError: 158369:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 12 previous similar messages [ 6694.060753] LustreError: 168068:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787847815 with bad export cookie 5038765171025963933 [ 6694.074026] LustreError: 168068:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 6694.075699] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6694.639742] Lustre: server umount lustre-MDT0001 complete [ 6709.750599] Lustre: server umount lustre-OST0000 complete [ 6710.752106] Lustre: 3653:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787847816/real 1787847816] req@ffff8d80fa33da40 x1874687441349248/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787847832 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6713.789960] Lustre: server umount lustre-OST0001 complete [ 6731.497484] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 6741.388712] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6742.034166] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6742.040582] Lustre: Skipped 1 previous similar message [ 6746.866657] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6755.615264] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6756.138306] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6761.807685] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6765.296794] Lustre: 185494:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 6772.885507] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6773.299334] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6780.857807] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6781.491512] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:161) [ 6787.577985] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:812 to 0x280000401:833) [ 6792.226141] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6797.804233] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:746 to 0x2c0000401:769) [ 6800.988580] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6810.210113] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6814.014604] Lustre: 187370:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 6880.828721] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 12:26:40 (1787848000) [ 6936.970732] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 12:27:36 (1787848056) [ 8452.543937] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 12:52:52 (1787849572) [ 8466.401108] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 8466.415651] 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 [ 8466.430574] Lustre: Skipped 1 previous similar message [ 8466.440106] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8470.055897] Lustre: server umount lustre-MDT0000 complete [ 8472.034969] LustreError: 184347:0:(ldlm_lib.c:1228: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. [ 8472.053879] LustreError: 184347:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 10 previous similar messages [ 8473.846920] LustreError: 185095:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787849595 with bad export cookie 5038765171025973047 [ 8473.849676] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8473.864506] LustreError: 185095:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 8474.160698] Lustre: server umount lustre-MDT0001 complete [ 8488.720096] Lustre: server umount lustre-OST0000 complete [ 8503.348778] Lustre: server umount lustre-OST0001 complete [ 8519.360668] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 8530.655534] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8531.228712] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8531.240049] Lustre: Skipped 1 previous similar message [ 8535.964495] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8536.547829] LustreError: 194723:0:(ldlm_lib.c:1228: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. [ 8536.583542] LustreError: 194723:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 1 previous similar message [ 8545.347786] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8545.715909] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 8550.318363] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8553.184909] Lustre: 195864:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 8560.923113] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 8561.441442] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 8568.996872] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8569.677693] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:193) [ 8575.858027] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:5835 to 0x280000401:5857) [ 8578.452312] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 8578.933710] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 8584.173910] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:5771 to 0x2c0000401:5793) [ 8585.965504] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8593.421388] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8596.955540] Lustre: 197738:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 8625.670233] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 12:55:45 (1787849745) [ 8653.928441] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 12:56:13 (1787849773) [ 8682.721180] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 12:56:42 (1787849802) [ 8717.146189] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 12:57:16 (1787849836) [ 8761.784867] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 12:58:00 (1787849880) [ 8844.897498] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 12:59:25 (1787849965) [ 8878.076687] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 12:59:58 (1787849998) [ 8944.495467] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 13:01:03 (1787850063) [ 8951.595703] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8951.598677] Lustre: Skipped 2 previous similar messages [ 8953.608276] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8953.610114] Lustre: Skipped 90 previous similar messages [ 8957.624705] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8957.628053] Lustre: Skipped 186 previous similar messages [ 8965.672299] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8965.677764] Lustre: Skipped 369 previous similar messages [ 8981.674700] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8981.678616] Lustre: Skipped 844 previous similar messages [ 9013.681739] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9013.683514] Lustre: Skipped 1992 previous similar messages [ 9077.713537] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9077.718133] Lustre: Skipped 3287 previous similar messages [ 9389.686408] Lustre: *** cfs_fail_loc=a08, val=0*** [ 9389.688134] Lustre: Skipped 1225 previous similar messages [ 9389.695223] Lustre: *** cfs_fail_loc=a08, val=0*** [ 9389.703106] Lustre: Skipped 2 previous similar messages [ 9423.850511] 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 [ 9423.866389] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 9423.885293] Lustre: Skipped 6 previous similar messages [ 9423.924319] Lustre: Skipped 6 previous similar messages [ 9428.921860] Lustre: server umount lustre-MDT0000 complete [ 9428.975491] LustreError: 194719:0:(ldlm_lib.c:1228: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. [ 9429.016836] LustreError: 194719:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 7 previous similar messages [ 9432.777418] LustreError: 206470:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787850554 with bad export cookie 5038765171027748625 [ 9432.790656] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 9432.793784] LustreError: 206470:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 9434.083586] 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 [ 9434.087357] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 9434.109305] Lustre: Skipped 1 previous similar message [ 9434.125804] Lustre: Skipped 1 previous similar message [ 9437.091633] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 9437.109814] Lustre: Skipped 1 previous similar message [ 9442.274300] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 9447.392212] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 9447.938410] Lustre: server umount lustre-MDT0001 complete [ 9453.223308] Lustre: server umount lustre-OST0000 complete [ 9457.849864] Lustre: server umount lustre-OST0001 complete [ 9467.806077] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_hostid [ 9477.622190] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 9528.900214] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [ 9540.973549] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 9541.333992] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 9541.395381] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 9541.508976] Lustre: lustre-MDT0000: new disk, initializing [ 9541.649903] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 9541.696358] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 9546.807122] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9559.790879] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 9559.957260] Lustre: 214215:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 9559.986712] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 9559.990147] Lustre: Skipped 1 previous similar message [ 9560.076398] Lustre: lustre-MDT0001: new disk, initializing [ 9560.175063] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 9560.210894] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 9560.227194] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 9565.788614] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9571.398341] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 9578.189762] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 9578.455690] Lustre: lustre-OST0000: new disk, initializing [ 9578.459301] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 9578.464503] Lustre: 215848:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 9578.530963] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 9580.085629] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 9580.096231] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 9580.231464] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 9585.310578] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9597.426400] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 9597.564537] Lustre: lustre-OST0001: new disk, initializing [ 9597.577200] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 9597.580196] Lustre: 216720:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 9597.674945] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 9598.886846] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 9598.897828] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 9598.977442] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 9604.971379] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9616.534543] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 9620.685932] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 9652.237193] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 13:12:51 (1787850771) [ 9661.686622] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 13:13:01 (1787850781) [ 9697.733697] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 13:13:36 (1787850816) [ 9760.641298] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 13:14:40 (1787850880) [ 9788.457836] Lustre: DEBUG MARKER: rename directory return 255 [ 9828.694485] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 13:15:48 (1787850948) [ 9850.836903] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 13:16:10 (1787850970) [ 9887.110518] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 13:16:46 (1787851006) [10036.959655] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 13:19:16 (1787851156) [10066.246996] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 13:19:46 (1787851186) [10103.870121] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 13:20:23 (1787851223) [10258.974067] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 13:22:58 (1787851378) [10264.547221] 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 [10264.564951] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10264.574164] Lustre: Skipped 3 previous similar messages [10264.591408] Lustre: Skipped 6 previous similar messages [10269.385805] Lustre: server umount lustre-MDT0000 complete [10269.679880] LustreError: 224190:0:(ldlm_lib.c:1228: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. [10269.712986] LustreError: 224190:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 11 previous similar messages [10273.212170] LustreError: 214206:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787851394 with bad export cookie 5038765171028120801 [10273.213590] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10273.235060] LustreError: 214206:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [10273.779079] Lustre: server umount lustre-MDT0001 complete [10289.077768] Lustre: server umount lustre-OST0000 complete [10290.976199] Lustre: 3655:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787851396/real 1787851396] req@ffff8d7fd56ec780 x1874687451804928/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787851412 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [10290.996750] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [10294.436178] Lustre: server umount lustre-OST0001 complete [10315.987840] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [10328.417085] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10328.864805] LustreError: 234068:0:(ldlm_lib.c:1228: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. [10328.951597] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10328.963222] 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 [10333.774409] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10334.178412] LustreError: 234069:0:(ldlm_lib.c:1228: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. [10343.098073] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10343.412547] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [10343.418899] 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 [10348.344985] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10351.891340] Lustre: 235214:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10358.816413] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10359.149735] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [10359.165285] 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 [10366.328468] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10369.392282] LustreError: 235567:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [10369.414830] LustreError: 235567:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 1 previous similar message [10374.585384] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:20 to 0x280000401:65) [10376.272107] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10376.694137] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [10376.727755] 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 [10381.832914] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:65) [10385.290028] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10395.166631] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10399.675725] Lustre: 237091:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10406.761490] LustreError: 234063:0:(osd_handler.c:3425:osd_quota_transfer()) lustre-MDT0000: quota transfer failed. Is project enforcement enabled on the ldiskfs filesystem? rc = -95 [10412.515720] 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 [10412.520680] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10412.530593] Lustre: Skipped 2 previous similar messages [10412.538491] Lustre: Skipped 1 previous similar message [10417.643101] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10417.652994] Lustre: Skipped 3 previous similar messages [10418.201423] Lustre: server umount lustre-MDT0000 complete [10422.200877] LustreError: 234048:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787851543 with bad export cookie 5038765171028169661 [10422.208852] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10422.211382] LustreError: 234048:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [10422.755530] 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 [10422.761108] LustreError: 234063:0:(ldlm_lib.c:1228: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. [10422.769414] Lustre: Skipped 1 previous similar message [10422.796690] LustreError: 234063:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 5 previous similar messages [10422.956040] Lustre: server umount lustre-MDT0001 complete [10429.491422] Lustre: server umount lustre-OST0000 complete [10433.492881] Lustre: server umount lustre-OST0001 complete [10456.943689] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [10469.670628] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10470.149153] LustreError: 239479:0:(ldlm_lib.c:1228: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. [10470.268138] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10476.268184] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10487.183031] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10493.323360] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10497.035326] Lustre: 240627:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10506.186259] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10514.800431] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:67 to 0x280000401:97) [10515.353791] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10524.767904] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10530.301058] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:97) [10532.911889] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10541.054940] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10544.585440] Lustre: 242504:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10574.070341] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 13:28:13 (1787851693) [10630.716914] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [10632.888362] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 13:29:12 (1787851752) [10660.299894] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [10661.891692] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 13:29:41 (1787851781) [10713.202811] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [10715.021164] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 13:30:34 (1787851834) [10749.000543] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 13:31:08 (1787851868) [10761.637533] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [10767.255886] Lustre: 248925:0:(qsd_reint.c:249:qsd_reint_index()) lustre-OST0000: index version for fid [0x200000005:0x1007:0x0] is 0, but index isn't empty (1) [10773.206408] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [10779.378124] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [10783.797805] Lustre: DEBUG MARKER: Write... [10804.719509] LustreError: 250271:0:(mgs_handler.c:1144:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [10809.883810] Lustre: DEBUG MARKER: Write... [10821.162584] Lustre: DEBUG MARKER: Write... [10897.150144] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 13:33:36 (1787852016) [10922.673968] LustreError: 254189:0:(mgs_handler.c:1144:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [10967.324770] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 13:34:47 (1787852087) [10993.101602] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [10994.836688] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [11082.627267] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 13:36:42 (1787852202) [11141.586614] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 13:37:40 (1787852260) [11180.831593] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 13:38:20 (1787852300) [11193.724701] Lustre: DEBUG MARKER: User quota (block hardlimit:100 MB) [11217.549739] Lustre: DEBUG MARKER: Write... [11219.424339] Lustre: DEBUG MARKER: Write out of block quota ... [11314.515263] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 13:40:34 (1787852434) [11325.973136] Lustre: DEBUG MARKER: User quota (block hardlimit:1000 MB) [11353.773540] LustreError: 239720:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool2 id:60000 enforced:1 hard:10240 soft:0 granted:10240 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11413.595207] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 13:42:13 (1787852533) [11427.800258] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [11453.945498] Lustre: DEBUG MARKER: Write... [11456.145246] Lustre: DEBUG MARKER: Write out of block quota ... [11456.527681] LustreError: 239477:0:(qmt_entry.c:558: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 [11515.024911] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 13:43:54 (1787852634) [11541.084841] Lustre: DEBUG MARKER: set to use default quota [11543.150841] Lustre: DEBUG MARKER: set default quota [11545.259701] Lustre: DEBUG MARKER: get default quota [11554.332401] Lustre: DEBUG MARKER: Test not out of quota [11561.520039] Lustre: DEBUG MARKER: Test out of quota [11572.667423] Lustre: DEBUG MARKER: Increase default quota [11601.838140] Lustre: DEBUG MARKER: Set quota to override default quota [11601.953021] LustreError: 240828:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:20480 soft:20480 granted:45056 time:1788457523 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11614.883475] Lustre: DEBUG MARKER: Set to use default quota again [11633.729657] Lustre: DEBUG MARKER: Cleanup [11699.530773] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 13:46:59 (1787852819) [11726.435433] Lustre: DEBUG MARKER: set default quota for qpool1 [11728.324178] Lustre: DEBUG MARKER: Write from user that hasn't lqe [11777.956552] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 13:48:17 (1787852897) [11865.074406] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 13:49:44 (1787852984) [11926.329387] Lustre: DEBUG MARKER: Write... [11928.985673] Lustre: DEBUG MARKER: Write out of block quota ... [12029.676443] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 13:52:28 (1787853148) [12069.968067] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 13:53:09 (1787853189) [12079.229398] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 13:53:18 (1787853198) [12119.313315] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 13:53:59 (1787853239) [12163.866553] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 13:54:43 (1787853283) [12188.213806] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 13:55:07 (1787853307) [12217.216976] Lustre: *** cfs_fail_loc=a06, val=0*** [12217.608192] LustreError: 239493:0:(qmt_lock.c:479:qmt_lvbo_update()) $$$ failed to release quota space on glimpse 0!=2048 : rc = -11 [12217.608192] qmt:lustre-QMT0000 pool:dt-0x0 id:60000 enforced:1 hard:102400 soft:0 granted:25600 time:0 qunit: 16384 edquot:0 may_rel:0 revoke:0 default:no [12222.913931] Lustre: Failing over lustre-OST0001 [12223.097650] Lustre: server umount lustre-OST0001 complete [12224.442990] LustreError: 240981:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-OST0001: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [12224.466594] LustreError: 240981:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 8 previous similar messages [12224.993068] LustreError: lustre-OST0001-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [12224.999897] Lustre: lustre-OST0001-osc-MDT0001: Connection to lustre-OST0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [12225.015292] LustreError: Skipped 1 previous similar message [12225.036519] Lustre: Skipped 1 previous similar message [12234.126676] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [12234.544267] Lustre: lustre-OST0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12234.569459] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [12234.644315] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [12236.558032] Lustre: lustre-OST0001: Recovery over after 0:02, of 3 clients 3 recovered and 0 were evicted. [12236.564575] Lustre: lustre-OST0001-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12236.600306] Lustre: Skipped 3 previous similar messages [12241.932069] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12291.242579] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 13:56:50 (1787853410) [12302.748706] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [12312.451363] LustreError: 293058:0:(qmt_pool.c:1407:qmt_pool_recalc()) cfs_fail_timeout id a07 sleeping for 10000ms [12312.458121] LustreError: 293058:0:(qmt_pool.c:1407:qmt_pool_recalc()) Skipped 5 previous similar messages [12320.225043] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [12320.243826] 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 [12320.255523] Lustre: Skipped 1 previous similar message [12320.268433] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [12321.713460] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.42@tcp (stopping) [12321.760451] LustreError: 3654:0:(client.c:1394:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff8d7fc6477840 x1874687454165120/t0(0) o601->lustre-MDT0000-lwp-MDT0000@0@lo:23/10 lens 336/336 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [12321.762221] 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 [12321.792820] LustreError: 3654:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -5, flags:0x8 qsd:lustre-MDT0000 qtype:grp lqe: ffff8d7fc7291080 id:0 enforced:0 granted: 0 pending:0 waiting:0 req:1 usage: 317 qunit:0 qtune:0 edquot:0 default:no revoke:0 [12321.799878] LustreError: lustre-MDT0000-lwp-MDT0001: operation quota_acquire to node 0@lo failed: rc = -107 [12321.863510] Lustre: Skipped 2 previous similar messages [12322.489325] LustreError: 293058:0:(qmt_pool.c:1407:qmt_pool_recalc()) cfs_fail_timeout id a07 awake [12322.772464] Lustre: server umount lustre-MDT0000 complete [12326.793983] LustreError: 239475:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [12326.818846] LustreError: 239475:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 5 previous similar messages [12331.604653] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [12331.743366] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [12331.925333] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.42@tcp (not set up) [12331.937400] Lustre: Skipped 4 previous similar messages [12332.111678] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [12332.115404] Lustre: Skipped 3 previous similar messages [12332.163375] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:129) [12332.165751] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:112 to 0x280000401:129) [12337.129732] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [12337.136693] Lustre: Skipped 1 previous similar message [12337.205951] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12368.802362] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 13:58:08 (1787853488) [12396.429212] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 13:58:36 (1787853516) [12418.496529] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 13:58:58 (1787853538) [12470.574542] Lustre: *** cfs_fail_loc=a08, val=0*** [12470.588131] Lustre: Skipped 2617 previous similar messages [12470.590756] Lustre: *** cfs_fail_loc=a08, val=0*** [12560.794349] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 14:01:20 (1787853680) [12588.738127] LustreError: 239477:0:(qmt_entry.c:558: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 [12639.384562] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 14:02:38 (1787853758) [12708.606451] LustreError: 239476:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1788458629 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [12848.205414] LustreError: 302919:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1788458769 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [12981.813595] LustreError: 240828:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:1000 enforced:1 hard:2048 soft:2048 granted:16384 time:1788458903 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [13086.928329] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 14:10:06 (1787854206) [13092.357700] Lustre: *** cfs_fail_loc=a09, val=0*** [13092.362655] Lustre: Skipped 1 previous similar message [13146.039228] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.42@tcp (stopping) [13146.082132] 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 [13146.094562] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [13146.127765] Lustre: Skipped 3 previous similar messages [13146.150130] LustreError: Skipped 1 previous similar message [13151.131698] LustreError: 239476:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13151.185228] LustreError: 239476:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 4 previous similar messages [13151.276409] Lustre: server umount lustre-MDT0000 complete [13156.257239] LustreError: 302919:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13156.289474] LustreError: 302919:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 4 previous similar messages [13160.937174] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13161.303399] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13161.361903] LustreError: 240828:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13161.382686] LustreError: 240828:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 4 previous similar messages [13161.802487] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13161.900535] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:132 to 0x280000401:161) [13161.904617] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:161) [13167.083600] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13167.120863] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [13167.132163] Lustre: Skipped 4 previous similar messages [13167.803560] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13188.758602] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 14:11:48 (1787854308) [13190.507969] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [13192.886166] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 14:11:52 (1787854312) [13213.818697] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 14:12:14 (1787854334) [13229.515606] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 14:12:29 (1787854349) [13251.234666] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 14:12:50 (1787854370) [13269.488152] 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 [13269.489845] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13269.490313] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [13269.505981] Lustre: Skipped 3 previous similar messages [13269.520797] Lustre: Skipped 7 previous similar messages [13274.596411] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13274.603729] Lustre: Skipped 3 previous similar messages [13279.717523] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13279.724797] Lustre: Skipped 3 previous similar messages [13280.224143] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [13280.421857] Lustre: server umount lustre-MDT0000 complete [13284.072185] LustreError: 265127:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787854405 with bad export cookie 5038765171029274170 [13284.075899] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13284.085318] LustreError: 265127:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [13284.834150] LustreError: 240828:0:(ldlm_lib.c:1228: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. [13284.834625] 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 [13284.835558] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [13284.851404] LustreError: 240828:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 5 previous similar messages [13284.889107] Lustre: Skipped 1 previous similar message [13290.604587] Lustre: server umount lustre-MDT0001 complete [13300.898580] Lustre: server umount lustre-OST0000 complete [13310.725550] Lustre: server umount lustre-OST0001 complete [13316.161964] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_hostid [13322.059868] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [13356.507566] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13356.754559] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [13356.779923] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [13356.866570] Lustre: lustre-MDT0000: new disk, initializing [13356.960298] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13356.974268] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [13361.142511] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13369.624954] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [13375.696129] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13375.905452] Lustre: lustre-OST0000: new disk, initializing [13375.909487] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [13375.913248] Lustre: Skipped 1 previous similar message [13375.918289] Lustre: 311712:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13375.965269] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [13377.420655] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [13377.429861] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [13377.467740] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [13382.283465] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13393.057919] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [13399.537594] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13399.712634] Lustre: lustre-OST0001: new disk, initializing [13399.717575] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [13399.725808] Lustre: 312770:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13399.793855] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [13401.312723] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [13401.320520] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [13401.348718] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [13406.305962] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13415.489860] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [13426.587754] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.42@tcp (stopping) [13426.594292] Lustre: Skipped 3 previous similar messages [13427.170481] 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 [13427.179646] Lustre: Skipped 1 previous similar message [13432.434309] Lustre: server umount lustre-MDT0000 complete [13444.307244] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13444.394941] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13444.622117] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13449.509829] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13456.853386] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [13456.887944] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [13459.590846] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 1 sec [13460.954267] LustreError: 314448:0:(qmt_entry.c:1150:qmt_map_lge_idx()) qmt: cannot map ostidx 0, num_used 1: rc = -22 [13461.494599] LustreError: 314449:0:(qmt_entry.c:1150:qmt_map_lge_idx()) qmt: cannot map ostidx 0, num_used 1: rc = -22 [13463.382718] LustreError: 314448:0:(qmt_entry.c:1150:qmt_map_lge_idx()) qmt: cannot map ostidx 0, num_used 1: rc = -22 [13467.105716] 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 [13467.106437] LustreError: 314445:0:(ldlm_lib.c:1228: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. [13467.128371] Lustre: Skipped 1 previous similar message [13467.150372] LustreError: 314445:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 2 previous similar messages [13468.664667] Lustre: server umount lustre-MDT0000 complete [13475.939130] LustreError: 310707:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787854597 with bad export cookie 5038765171029276795 [13475.952457] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13475.955711] LustreError: 310707:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [13476.051908] Lustre: server umount lustre-OST0000 complete [13479.870705] Lustre: server umount lustre-OST0001 complete [13498.961467] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_hostid [13505.357684] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [13551.274740] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing load_modules_local [13561.199390] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13561.357114] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [13561.375164] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [13561.431823] Lustre: lustre-MDT0000: new disk, initializing [13561.486933] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13561.500152] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [13565.548320] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13575.549389] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13575.623597] Lustre: 319259:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [13575.721744] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [13575.727726] Lustre: Skipped 1 previous similar message [13575.807455] Lustre: lustre-MDT0001: new disk, initializing [13575.975567] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [13575.999123] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [13580.392339] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13584.997914] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [13590.981885] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13591.148873] Lustre: lustre-OST0000: new disk, initializing [13591.153439] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [13591.159617] Lustre: 320888:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13593.239567] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [13593.249935] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [13593.361472] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [13597.304093] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13607.376917] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13607.514178] Lustre: lustre-OST0001: new disk, initializing [13607.523606] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [13607.529270] Lustre: 321757:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13607.611214] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [13607.616153] Lustre: Skipped 2 previous similar messages [13609.442379] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [13609.457276] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [13609.574389] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [13613.966392] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13622.856920] Lustre: DEBUG MARKER: Using TIMEOUT=20 [13626.669371] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [13634.213700] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 14:19:14 (1787854754) [13650.320662] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 14:19:30 (1787854770) [13670.023979] Lustre: *** cfs_fail_loc=170c, val=0*** [13723.589355] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 14:20:42 (1787854842) [13755.364848] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [13755.374722] 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 [13755.392870] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13755.401043] Lustre: Skipped 5 previous similar messages [13760.792902] Lustre: server umount lustre-MDT0000 complete [13761.422119] LustreError: 319266:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13772.150777] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13772.323641] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13772.662664] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13772.746338] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:33) [13777.897543] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13777.912901] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [13777.922031] Lustre: Skipped 1 previous similar message [13779.003300] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13792.165173] Lustre: lustre-MDT0000: Not available for connect from 192.168.201.42@tcp (stopping) [13792.175058] Lustre: Skipped 5 previous similar messages [13793.252349] 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 [13793.255587] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [13793.287726] Lustre: Skipped 4 previous similar messages [13795.058053] Lustre: server umount lustre-MDT0000 complete [13803.723498] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13803.860851] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13804.161268] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:65) [13808.498897] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13809.122462] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13815.297827] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 14:22:15 (1787854935) [13840.760165] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 14:22:40 (1787854960) [13875.651655] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 14:23:15 (1787854995) [13877.165941] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 OST is too small, skip the test [13878.799523] Lustre: DEBUG MARKER: == sanity-quota test 97a: LQA control commands =========== 14:23:18 (1787854998) [13903.254805] LustreError: 332573:0:(qmt_lqa.c:79:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-dt-lqa1: rc = -2 [13903.264154] LustreError: 332573:0:(qmt_lqa.c:84:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-md-lqa1: rc = -2 [13904.807229] Lustre: DEBUG MARKER: == sanity-quota test 97b: Check LQA internals ============ 14:23:44 (1787855024) [13921.820868] LustreError: 333469:0:(qmt_lqa.c:250:qmt_lqa_insert_range()) lustre-QMT0000: LQA range 15-31 partially overlaps with existing range 10-19: rc = -34 [13921.841370] LustreError: 333469:0:(qmt_lqa.c:669:qmt_lqa_add()) lustre-QMT0000: lqa:lqa1 can't add range 15:31: rc = -17 [13925.316820] LustreError: 333666:0:(qmt_lqa.c:825:qmt_lqa_remove()) lustre-QMT0000: lqa-md-lqa1 cannot remove range 10:19: rc = -2 [13935.892424] Lustre: DEBUG MARKER: adding 50 LQA ranges took 2s [13940.314854] Lustre: DEBUG MARKER: Removing 50 LQA ranges took 2s [13948.266909] Lustre: DEBUG MARKER: == sanity-quota test 97c: LQA lfs quota commands and MDS restart consistency ========================================================== 14:24:28 (1787855068) [13952.627234] Lustre: Failing over lustre-MDT0000 [13954.893733] Lustre: server umount lustre-MDT0000 complete [13956.020050] LustreError: 322735:0:(ldlm_lib.c:1228:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.201.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13956.039250] LustreError: 322735:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 20 previous similar messages [13957.611030] 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 [13957.621949] Lustre: Skipped 4 previous similar messages [13962.496357] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13962.570584] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13962.783351] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13962.788052] Lustre: Skipped 1 previous similar message [13962.826970] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [13966.218611] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [13966.940156] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13967.853293] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [13967.857832] Lustre: Skipped 6 previous similar messages [13967.871025] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [13967.918755] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:97) [13971.821602] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [13979.405323] Lustre: DEBUG MARKER: == sanity-quota test 97d: LQA disk persistence using standard commands ========================================================== 14:24:59 (1787855099) [13994.962654] Lustre: Failing over lustre-MDT0000 [13995.288553] Lustre: server umount lustre-MDT0000 complete [13998.563793] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14003.465712] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14003.581258] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14003.681395] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [14003.684155] Lustre: Skipped 4 previous similar messages [14003.795700] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [14007.175625] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [14007.825557] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14008.814571] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [14008.872352] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:129) [14013.568852] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [14044.914565] Lustre: DEBUG MARKER: == sanity-quota test 97e: LQA add/remove should reject invalid ranges ========================================================== 14:26:04 (1787855164) [14058.376522] LustreError: 339809:0:(qmt_lqa.c:79:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-dt-lqa1: rc = -2 [14058.389200] LustreError: 339809:0:(qmt_lqa.c:84:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-md-lqa1: rc = -2 [14060.501790] Lustre: DEBUG MARKER: == sanity-quota test 98: Verify MDT retry on -EDQUOT during mkdir ========================================================== 14:26:20 (1787855180) [14068.899571] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [14071.201874] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [14077.584150] Lustre: DEBUG MARKER: oleg142-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [14079.574649] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [14086.781896] Lustre: *** cfs_fail_loc=a02, val=1*** [14086.789631] LustreError: 319266:0:(lod_object.c:6432:lod_declare_create()) lustre-MDT0000-mdtlov: Injecting -EDQUOT for directory create on MDT0000 (fail_val=1): rc = -122 [14097.044523] Lustre: DEBUG MARKER: == sanity-quota test 300: inode quota with MDT directory migration at 80% limit ========================================================== 14:26:56 (1787855216) [14117.127903] Lustre: DEBUG MARKER: Creating 819 files as quota_usr ... [14129.276401] Lustre: DEBUG MARKER: Migrating directory from MDT0 to MDT1 ... [14188.471656] Lustre: DEBUG MARKER: Migration completed successfully [14220.974633] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 13870 sec ======== 14:29:00 (1787855340) [14223.137196] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 14:29:02 (1787855342) === [14227.230333] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 14:29:07 (1787855347) === [14234.081828] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14234.083503] 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 [14234.084875] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [14234.113357] Lustre: Skipped 8 previous similar messages [14238.042446] Lustre: server umount lustre-MDT0000 complete [14239.200749] LustreError: 319264:0:(ldlm_lib.c:1228: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. [14239.229356] LustreError: 319264:0:(ldlm_lib.c:1228:target_handle_connect()) Skipped 14 previous similar messages [14246.854160] LustreError: 341589:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1787855368 with bad export cookie 5038765171029283326 [14246.869297] LustreError: MGC192.168.201.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14246.877138] LustreError: 341589:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [14247.372539] Lustre: server umount lustre-MDT0001 complete [14265.632210] Lustre: 3655:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787855370/real 1787855370] req@ffff8d7fd74592c0 x1874687457756032/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787855386 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14265.767056] Lustre: server umount lustre-OST0000 complete [14266.848199] Lustre: 3654:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787855372/real 1787855372] req@ffff8d7fc997e1c0 x1874687457756288/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787855388 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14269.792798] Lustre: 3655:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787855375/real 1787855375] req@ffff8d7fd745a1c0 x1874687457756544/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787855391 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14272.928108] Lustre: 3655:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1787855378/real 1787855378] req@ffff8d80f7357c00 x1874687457756928/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1787855394 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14276.292552] Lustre: server umount lustre-OST0001 complete [14296.144351] Lustre: DEBUG MARKER: oleg142-server.virtnet: executing unload_modules_local [14299.372910] Key type lgssc unregistered [14299.727542] LNet: 344847:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [14299.735440] LNetError: 344847:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [14299.752304] LNet: Removed LNI 192.168.201.142@tcp [14300.619706] Key type .llcrypt unregistered [14300.624434] Key type ._llcrypt unregistered