[ 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-8.fc42 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 543768323 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 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2895240K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001013] APIC: Switch to symmetric I/O mode setup [ 0.003168] x2apic enabled [ 0.004011] Switched APIC routing to physical x2apic. [ 0.005015] kvm-guest: setup PV IPIs [ 0.008495] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009044] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010015] pid_max: default: 32768 minimum: 301 [ 0.011159] LSM: Security Framework initializing [ 0.012082] Yama: becoming mindful. [ 0.013047] SELinux: Initializing. [ 0.014074] *** VALIDATE selinux *** [ 0.022798] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027102] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029124] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030108] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031113] *** VALIDATE tmpfs *** [ 0.032371] *** VALIDATE proc *** [ 0.033206] *** VALIDATE cgroup *** [ 0.034009] *** VALIDATE cgroup2 *** [ 0.035249] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.036175] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.037011] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.038033] Spectre V2 : User space: Vulnerable [ 0.039007] Speculative Store Bypass: Vulnerable [ 0.041863] debug: unmapping init [mem 0xffffffffb3259000-0xffffffffb3260fff] [ 0.044000] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044732] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045028] ... version: 2 [ 0.046016] ... bit width: 48 [ 0.047014] ... generic registers: 4 [ 0.048021] ... value mask: 0000ffffffffffff [ 0.049031] ... max period: 00007fffffffffff [ 0.050021] ... fixed-purpose events: 3 [ 0.051014] ... event mask: 000000070000000f [ 0.052388] rcu: Hierarchical SRCU implementation. [ 0.054580] smp: Bringing up secondary CPUs ... [ 0.055645] x86: Booting SMP configuration: [ 0.056030] .... node #0, CPUs: #1 #2 #3 [ 0.063151] smp: Brought up 1 node, 4 CPUs [ 0.065012] smpboot: Max logical packages: 1 [ 0.066013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.129151] node 0 deferred pages initialised in 61ms [ 0.132142] devtmpfs: initialized [ 0.133283] x86/mm: Memory block size: 128MB [ 0.136961] gcov: version magic: 0x41383552 [ 0.139300] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.143094] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.145381] pinctrl core: initialized pinctrl subsystem [ 0.148458] [ 0.148915] ************************************************************* [ 0.151015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.152007] ** ** [ 0.154010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.155010] ** ** [ 0.156007] ** This means that this kernel is built to expose internal ** [ 0.158009] ** IOMMU data structures, which may compromise security on ** [ 0.159008] ** your system. ** [ 0.160009] ** ** [ 0.162007] ** If you see this message and you are not debugging the ** [ 0.163009] ** kernel, report this immediately to your vendor! ** [ 0.165012] ** ** [ 0.167010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.168008] ************************************************************* [ 0.170718] NET: Registered protocol family 16 [ 0.172494] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.174081] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.177053] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.179487] cpuidle: using governor menu [ 0.180416] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.182477] PCI: Using configuration type 1 for base access [ 0.184122] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.193129] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.195056] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.198137] cryptd: max_cpu_qlen set to 1000 [ 0.200239] ACPI: Added _OSI(Module Device) [ 0.202064] ACPI: Added _OSI(Processor Device) [ 0.203019] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.204013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.209013] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.214534] ACPI: Interpreter enabled [ 0.216072] ACPI: PM: (supports S0 S3 S4 S5) [ 0.218016] ACPI: Using IOAPIC for interrupt routing [ 0.219128] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.222388] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.230722] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.232048] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.233012] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.235078] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.238940] acpiphp: Slot [2] registered [ 0.239072] acpiphp: Slot [5] registered [ 0.240043] acpiphp: Slot [6] registered [ 0.240945] acpiphp: Slot [7] registered [ 0.242068] acpiphp: Slot [8] registered [ 0.242927] acpiphp: Slot [9] registered [ 0.244060] acpiphp: Slot [10] registered [ 0.244922] acpiphp: Slot [3] registered [ 0.245098] acpiphp: Slot [4] registered [ 0.246025] acpiphp: Slot [11] registered [ 0.246873] acpiphp: Slot [12] registered [ 0.248051] acpiphp: Slot [13] registered [ 0.249094] acpiphp: Slot [14] registered [ 0.250147] acpiphp: Slot [15] registered [ 0.252080] acpiphp: Slot [16] registered [ 0.253089] acpiphp: Slot [17] registered [ 0.254120] acpiphp: Slot [18] registered [ 0.255167] acpiphp: Slot [19] registered [ 0.257112] acpiphp: Slot [20] registered [ 0.259136] acpiphp: Slot [21] registered [ 0.260107] acpiphp: Slot [22] registered [ 0.261279] acpiphp: Slot [23] registered [ 0.263136] acpiphp: Slot [24] registered [ 0.265116] acpiphp: Slot [25] registered [ 0.266127] acpiphp: Slot [26] registered [ 0.267103] acpiphp: Slot [27] registered [ 0.269124] acpiphp: Slot [28] registered [ 0.271103] acpiphp: Slot [29] registered [ 0.272154] acpiphp: Slot [30] registered [ 0.273138] acpiphp: Slot [31] registered [ 0.275069] PCI host bridge to bus 0000:00 [ 0.276020] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.279048] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.281029] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.284034] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.286026] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.289028] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.290205] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.293010] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.296101] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.306869] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.313090] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.315016] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.317014] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.319015] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.320290] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.322519] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.324026] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.326868] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.331014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.344021] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.349869] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.354818] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.363019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.374018] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.406021] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.414272] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.426018] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.435018] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.462019] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.470580] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.479017] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.488017] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.511034] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.524281] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.533089] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.538016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.551015] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.559197] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.569025] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.576041] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.594037] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.604887] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.612030] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.620019] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.638023] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.647511] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.649460] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.651308] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.653354] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.655231] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.659149] iommu: Default domain type: Passthrough [ 0.660539] SCSI subsystem initialized [ 0.662136] ACPI: bus type USB registered [ 0.663103] usbcore: registered new interface driver usbfs [ 0.665067] usbcore: registered new interface driver hub [ 0.666103] usbcore: registered new device driver usb [ 0.668165] pps_core: LinuxPPS API ver. 1 registered [ 0.669009] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.671064] PTP clock support registered [ 0.673081] EDAC MC: Ver: 3.0.0 [ 0.674140] PCI: Using ACPI for IRQ routing [ 0.675631] NetLabel: Initializing [ 0.676007] NetLabel: domain hash size = 128 [ 0.676849] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.678065] NetLabel: unlabeled traffic allowed by default [ 0.680154] vgaarb: loaded [ 0.681194] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.682007] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.686314] clocksource: Switched to clocksource kvm-clock [ 0.808435] VFS: Disk quotas dquot_6.6.0 [ 0.810015] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.812294] *** VALIDATE ramfs *** [ 0.813694] *** VALIDATE hugetlbfs *** [ 0.815188] pnp: PnP ACPI init [ 0.817148] pnp: PnP ACPI: found 6 devices [ 0.843275] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.846587] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.849131] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.851556] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.854106] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.856282] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.859261] NET: Registered protocol family 2 [ 0.862106] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.867821] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.871440] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.876803] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.880280] TCP: Hash tables configured (established 65536 bind 65536) [ 0.883268] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.885651] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.888550] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.891599] NET: Registered protocol family 1 [ 0.894748] RPC: Registered named UNIX socket transport module. [ 0.896801] RPC: Registered udp transport module. [ 0.898427] RPC: Registered tcp transport module. [ 0.900019] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.902430] NET: Registered protocol family 44 [ 0.903977] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.907271] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.909821] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.912565] PCI: CLS 0 bytes, default 64 [ 0.914355] Unpacking initramfs... [ 2.339790] debug: unmapping init [mem 0xffff89d93cc54000-0xffff89d93ffbffff] [ 2.343771] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.345720] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.348270] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.877850] Initialise system trusted keyrings [ 2.879576] Key type blacklist registered [ 2.881591] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.890728] zbud: loaded [ 2.894262] *** VALIDATE nfs *** [ 2.895691] *** VALIDATE nfs4 *** [ 2.898231] pstore: using deflate compression [ 2.902835] Platform Keyring initialized [ 3.017831] NET: Registered protocol family 38 [ 3.019844] Key type asymmetric registered [ 3.021325] Asymmetric key parser 'x509' registered [ 3.023200] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.026087] io scheduler mq-deadline registered [ 3.027748] io scheduler kyber registered [ 3.029629] io scheduler bfq registered [ 3.031703] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.034509] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.036909] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.039323] ACPI: Power Button [PWRF] [ 3.045914] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.052465] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.066308] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.076368] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.097269] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.125063] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.153990] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.158457] Non-volatile memory driver v1.3 [ 3.160151] Linux agpgart interface v0.103 [ 3.193568] virtio_blk virtio1: [vda] 141800 512-byte logical blocks (72.6 MB/69.2 MiB) [ 3.196504] vda: detected capacity change from 0 to 72601600 [ 3.212580] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.215502] vdb: detected capacity change from 0 to 1073741824 [ 3.234098] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.237218] vdc: detected capacity change from 0 to 2621440000 [ 3.254619] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.258444] vdd: detected capacity change from 0 to 2621440000 [ 3.281893] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.285529] vde: detected capacity change from 0 to 4294967296 [ 3.303081] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.306184] vdf: detected capacity change from 0 to 4294967296 [ 3.317416] libphy: Fixed MDIO Bus: probed [ 3.332499] usbcore: registered new interface driver usbserial_generic [ 3.335440] usbserial: USB Serial support registered for generic [ 3.337567] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.341375] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.343483] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.345552] mousedev: PS/2 mouse device common for all mice [ 3.348532] rtc_cmos 00:05: RTC can wake from S4 [ 3.352416] rtc_cmos 00:05: registered as rtc0 [ 3.354466] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.355270] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.359735] intel_pstate: CPU model not supported [ 3.362695] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.365067] hid: raw HID events driver (C) Jiri Kosina [ 3.367926] usbcore: registered new interface driver usbhid [ 3.368069] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.369871] usbhid: USB HID core driver [ 3.374298] drop_monitor: Initializing network drop monitor service [ 3.376510] Initializing XFRM netlink socket [ 3.377945] NET: Registered protocol family 10 [ 3.380460] Segment Routing with IPv6 [ 3.382207] NET: Registered protocol family 17 [ 3.383690] mpls_gso: MPLS GSO support [ 3.389176] RAS: Correctable Errors collector initialized. [ 3.392071] AVX version of gcm_enc/dec engaged. [ 3.393659] AES CTR mode by8 optimization enabled [ 3.474201] sched_clock: Marking stable (3474162784, 0)->(4393882935, -919720151) [ 3.476571] registered taskstats version 1 [ 3.478182] Loading compiled-in X.509 certificates [ 3.479583] zswap: loaded using pool lzo/zbud [ 3.498101] Key type big_key registered [ 3.509811] Key type encrypted registered [ 3.510927] ima: No TPM chip found, activating TPM-bypass! [ 3.512254] ima: Allocated hash algorithm: sha1 [ 3.513488] ima: No architecture policies found [ 3.514710] evm: Initialising EVM extended attributes: [ 3.516273] evm: security.selinux [ 3.516987] evm: security.ima [ 3.517840] evm: security.capability [ 3.518756] evm: HMAC attrs: 0x1 [ 3.520783] rtc_cmos 00:05: setting system clock to 2026-05-18 17:22:51 UTC (1779124971) [ 3.526419] debug: unmapping init [mem 0xffffffffb4203000-0xffffffffb43fffff] [ 3.528487] debug: unmapping init [mem 0xffffffffb2f82000-0xffffffffb3258fff] [ 3.535131] Write protecting the kernel read-only data: 28672k [ 3.537262] debug: unmapping init [mem 0xffffffffb1603000-0xffffffffb17fffff] [ 3.538970] debug: unmapping init [mem 0xffffffffb1f14000-0xffffffffb1ffffff] [ 3.573936] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.581455] systemd[1]: Detected virtualization kvm. [ 3.583259] systemd[1]: Detected architecture x86-64. [ 3.584608] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.611206] systemd[1]: No hostname configured. [ 3.612969] systemd[1]: Set hostname to . [ 3.614873] random: systemd: uninitialized urandom read (16 bytes read) [ 3.617396] systemd[1]: Initializing machine ID from random generator. [ 3.674934] random: ln: uninitialized urandom read (6 bytes read) [ 3.752562] random: systemd: uninitialized urandom read (16 bytes read) [ 3.754987] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 3.761799] systemd[1]: Reached target Local Encrypted Volumes. [ OK ] Reached target Local Encrypted Volumes. [ 3.766600] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Swap. [ OK ] Reached target Local File Systems. [ OK ] Listening on Journal Socket. Starting Journal Service... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Paths. [ OK ] Reached target Slices. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Reached target Timers. Starting Create Volatile Files and Directories... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.395761] device-mapper: uevent: version 1.0.3 [ 4.397855] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.137306] virtio_net virtio0 ens2: renamed from eth0 [ 5.158886] scsi host0: ata_piix [ 5.164963] random: fast init done [ 5.231276] scsi host1: ata_piix [ 5.296665] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.299185] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.538412] dracut-initqueue[588]: RTNETLINK answers: File exists [ 10.023127] random: crng init done [ 10.024503] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 10.496931] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Swap. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Apply Kernel Variables. Stopping udev Kernel Device Manager... [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.661941] printk: systemd: 25 output lines suppressed due to ratelimiting [ 11.942234] SELinux: Disabled at runtime. [ 12.009761] 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) [ 12.016994] systemd[1]: Detected virtualization kvm. [ 12.019040] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.478026] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.481064] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.484910] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.488300] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.492341] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.500454] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.508191] systemd[1]: Listening on initctl Compatibility Named Pipe. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Control Socket. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. Starting Remount Root and Kernel File Systems... [ OK ] Stopped target Initrd File Systems. Mounting Huge Pages File System... [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-getty.slice. Mounting POSIX Message Queue File System... Mounting Kernel Debug File System... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-serial\x2dgetty.slice. Activating swap /dev/disk/by-label/SWAP... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Starting Apply Kernel Variables... [ 12.688065] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Apply Kernel Variables. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ OK ] Started udev Coldplug all Devices. [ 13.041700] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.469205] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.499373] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.593745] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.612571] EDAC sbridge: Ver: 1.1.2 [ 15.317965] Key type dns_resolver registered [ 15.629251] NFS: Registering the id_resolver key type [ 15.631239] Key type id_resolver registered [ 15.632852] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Login Service... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg210-server login: [ 47.352765] libcfs: loading out-of-tree module taints kernel. [ 47.434856] Key type ._llcrypt registered [ 47.440495] Key type .llcrypt registered [ 47.633528] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [ 70.087616] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 72.306434] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 72.317449] alg: No test for adler32 (adler32-zlib) [ 73.976184] Lustre: Lustre: Build Version: 2.17.53_24_g2ff46d7 [ 75.120281] LNet: Added LNI 192.168.202.110@tcp [8/256/0/180] [ 76.952204] Key type lgssc registered [ 78.548717] Lustre: Echo OBD driver; http://www.lustre.org/ [ 99.050673] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 124.684127] hrtimer: interrupt took 9189287 ns [ 148.884329] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 165.287649] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 165.314119] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 166.632613] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 166.691424] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 166.868766] Lustre: lustre-MDT0000: new disk, initializing [ 166.988558] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 167.030446] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 171.764280] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 187.435168] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 187.576283] Lustre: 6548:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 187.637454] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 187.642944] Lustre: Skipped 1 previous similar message [ 187.769907] Lustre: lustre-MDT0001: new disk, initializing [ 187.881660] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 187.918258] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 187.940611] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 192.993074] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 199.148617] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 210.145682] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 210.597716] Lustre: lustre-OST0000: new disk, initializing [ 210.618938] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 210.634336] Lustre: 8449:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 210.647176] Lustre: lustre-OST0000: Not available for connect from 0@lo (not set up) [ 210.766977] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 216.091984] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 216.118160] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 216.195455] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 218.594461] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 237.626341] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 237.786684] Lustre: lustre-OST0001: new disk, initializing [ 237.790178] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 237.799938] Lustre: 9509:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 237.934453] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 245.295485] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 245.303603] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 245.439055] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 246.416946] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 260.119403] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 267.690490] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 275.138428] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing check_logdir /tmp/testlogs/ [ 280.629697] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing yml_node [ 285.578214] Lustre: DEBUG MARKER: Client: 2.17.53.24 [ 288.356588] Lustre: DEBUG MARKER: MDS: 2.17.53.24 [ 290.615776] Lustre: DEBUG MARKER: OSS: 2.17.53.24 [ 292.401435] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Mon May 18 13:27:37 EDT 2026 [ 310.936938] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 312.484982] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 [ 315.573499] Lustre: DEBUG MARKER: === sanity-quota: start setup 13:28:01 (1779125281) === [ 319.533875] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing check_config_client /mnt/lustre [ 341.152676] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 345.148597] Lustre: 13321:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 349.514908] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 355.853548] Lustre: DEBUG MARKER: === sanity-quota: finish setup 13:28:40 (1779125320) === [ 430.959229] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 13:29:56 (1779125396) [ 478.964829] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 13:30:44 (1779125444) [ 493.880387] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 503.241747] Lustre: DEBUG MARKER: Write... [ 506.201238] Lustre: DEBUG MARKER: Write out of block quota ... [ 543.303068] Lustre: DEBUG MARKER: -------------------------------------- [ 545.130934] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 552.392674] Lustre: DEBUG MARKER: Write... [ 555.440350] Lustre: DEBUG MARKER: Write out of block quota ... [ 597.378781] Lustre: DEBUG MARKER: -------------------------------------- [ 599.355769] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 602.802704] Lustre: DEBUG MARKER: Write... [ 605.302179] Lustre: DEBUG MARKER: Write out of block quota ... [ 664.738103] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 13:33:50 (1779125630) [ 679.234276] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 703.216594] Lustre: DEBUG MARKER: Write... [ 705.978854] Lustre: DEBUG MARKER: Write out of block quota ... [ 744.286465] Lustre: DEBUG MARKER: -------------------------------------- [ 745.817808] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 752.381104] Lustre: DEBUG MARKER: Write... [ 754.665045] Lustre: DEBUG MARKER: Write out of block quota ... [ 794.537316] Lustre: DEBUG MARKER: -------------------------------------- [ 796.341988] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 798.902442] Lustre: DEBUG MARKER: Write... [ 801.050952] Lustre: DEBUG MARKER: Write out of block quota ... [ 865.886543] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 13:37:10 (1779125830) [ 881.996596] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 912.741887] Lustre: DEBUG MARKER: Write... [ 916.074585] Lustre: DEBUG MARKER: Write out of block quota ... [ 1005.265539] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 13:39:30 (1779125970) [ 1017.063458] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 1045.162934] Lustre: DEBUG MARKER: Write... [ 1048.074306] Lustre: DEBUG MARKER: Write out of block quota ... [ 1132.813229] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 13:41:38 (1779126098) [ 1143.307502] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 1157.135165] Lustre: DEBUG MARKER: Write... [ 1159.695598] Lustre: DEBUG MARKER: Write out of block quota ... [ 1172.547252] Lustre: DEBUG MARKER: Write... [ 1224.888929] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 13:43:10 (1779126190) [ 1236.210538] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1250.086626] Lustre: DEBUG MARKER: Write... [ 1252.025375] Lustre: DEBUG MARKER: Write out of block quota ... [ 1285.401204] Lustre: DEBUG MARKER: Write... [ 1288.184966] Lustre: DEBUG MARKER: Write out of block quota ... [ 1335.980926] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 13:45:01 (1779126301) [ 1348.347423] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 1362.330728] Lustre: 6554:0:(osd_handler.c:2191:osd_trans_start()) lustre-MDT0000: credits 6570 > trans_max 3200 [ 1362.336525] Lustre: 6554:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 4/16/0, destroy: 0/0/0 [ 1362.342460] Lustre: 6554:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 401/401/0, xattr_set: 602/5615/0 [ 1362.349568] Lustre: 6554:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 20/142/0, punch: 0/0/0, quota 8/328/0 [ 1362.357832] Lustre: 6554:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/68/0, delete: 0/0/0 [ 1362.365925] Lustre: 6554:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1362.370442] CPU: 0 PID: 6554 Comm: mdt00_001 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [ 1362.377982] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 1362.385374] Call Trace: [ 1362.386681] ? dump_stack+0xbb/0x10e [ 1362.390239] ? osd_trans_start+0x8db/0x9d0 [osd_ldiskfs] [ 1362.393589] ? top_trans_start+0x599/0xd80 [ptlrpc] [ 1362.397822] ? lod_ref_add+0x30/0x30 [lod] [ 1362.400776] ? lod_trans_start+0x109/0x4c0 [lod] [ 1362.402223] ? mdd_declare_attr_set+0x190/0x690 [mdd] [ 1362.406484] ? mdd_env_info+0x25/0xc0 [mdd] [ 1362.409486] ? mdd_trans_start+0x18/0x30 [mdd] [ 1362.416634] ? mdd_attr_set+0xa5a/0x1240 [mdd] [ 1362.422557] ? mdt_reint_setattr+0x14aa/0x2030 [mdt] [ 1362.426428] ? mdt_reint_setattr+0x14aa/0x2030 [mdt] [ 1362.429987] ? mdt_reint_rec+0x139/0x2b0 [mdt] [ 1362.433375] ? mdt_reint_internal+0x693/0xdc0 [mdt] [ 1362.436449] ? mdt_reint+0x163/0x190 [mdt] [ 1362.440674] ? tgt_handle_request0+0x137/0xaf0 [ptlrpc] [ 1362.444846] ? tgt_request_handle+0x575/0x1f70 [ptlrpc] [ 1362.449687] ? ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [ 1362.453911] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [ 1362.457462] ? ptlrpc_main+0xce8/0x1400 [ptlrpc] [ 1362.461703] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [ 1362.467361] ? kthread+0x1d1/0x200 [ 1362.469980] ? set_kthread_struct+0x70/0x70 [ 1362.472887] ? ret_from_fork+0x1f/0x30 [ 1364.510734] Lustre: DEBUG MARKER: Write... [ 1376.586550] Lustre: DEBUG MARKER: Write out of block quota ... [ 1448.865038] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 13:46:54 (1779126414) [ 1459.494366] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 1465.334300] Lustre: DEBUG MARKER: Write 5MiB Using Fallocate [ 1472.215668] Lustre: DEBUG MARKER: Write 11MiB Using Fallocate [ 1554.283808] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 13:48:39 (1779126519) [ 1565.858066] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1584.171989] Lustre: DEBUG MARKER: Write... [ 1586.239430] Lustre: DEBUG MARKER: Write out of block quota ... [ 1617.958623] Lustre: DEBUG MARKER: Write... [ 1619.739787] Lustre: DEBUG MARKER: Write out of block quota ... [ 1632.731515] LustreError: 25518:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:15360 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 1672.364428] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 13:50:37 (1779126637) [ 1690.699628] Lustre: DEBUG MARKER: -------------------------------------- [ 1691.892922] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 2022.994724] Lustre: DEBUG MARKER: == sanity-quota test 1k: LQA: Block hard limit (normal use and out of quota) ========================================================== 13:56:27 (1779126987) [ 2042.419089] Lustre: DEBUG MARKER: Write... [ 2046.018681] Lustre: DEBUG MARKER: Write out of block quota ... [ 2076.020758] Lustre: DEBUG MARKER: Write... [ 2079.149427] Lustre: DEBUG MARKER: Write out of block quota ... [ 2110.981497] Lustre: DEBUG MARKER: Write... [ 2114.016705] Lustre: DEBUG MARKER: Write out of block quota ... [ 2157.241071] Lustre: DEBUG MARKER: == sanity-quota test 1l: Async writes should not be rejected by quota with root_prj_enable ========================================================== 13:58:42 (1779127122) [ 2199.905662] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 2201.745464] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 13:59:27 (1779127167) [ 2246.815708] Lustre: DEBUG MARKER: Write after timer goes off [ 2250.320480] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2292.082941] LustreError: 3655:0:(qsd_reint.c:627:qqi_reint_delayed()) lustre-OST0001: Delaying reintegration for qtype:0 until pending updates are flushed. [ 2334.870666] Lustre: DEBUG MARKER: Write after timer goes off [ 2337.081968] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2415.558806] Lustre: DEBUG MARKER: Write after timer goes off [ 2418.587281] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2487.833176] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 14:04:13 (1779127453) [ 2539.176813] Lustre: DEBUG MARKER: Write after timer goes off [ 2540.759547] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2617.254782] Lustre: DEBUG MARKER: Write after timer goes off [ 2620.129095] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2696.347334] Lustre: DEBUG MARKER: Write after timer goes off [ 2698.786508] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2782.047051] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 14:09:06 (1779127746) [ 2844.876285] Lustre: DEBUG MARKER: Write after timer goes off [ 2847.617087] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2920.129771] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 2921.914460] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 14:11:27 (1779127887) [ 2932.811335] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 3060.266431] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 14:13:45 (1779128025) [ 3105.249042] Lustre: *** cfs_fail_loc=513, val=601*** [ 3106.274373] Lustre: *** cfs_fail_loc=513, val=601*** [ 3107.292240] Lustre: *** cfs_fail_loc=513, val=601*** [ 3107.295708] Lustre: Skipped 12 previous similar messages [ 3107.400262] LustreError: 6556:0:(service.c:2344:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1865547824174720 [ 3109.345357] Lustre: *** cfs_fail_loc=513, val=601*** [ 3109.350835] Lustre: Skipped 21 previous similar messages [ 3113.953524] Lustre: *** cfs_fail_loc=513, val=601*** [ 3113.961234] Lustre: Skipped 21 previous similar messages [ 3118.051191] LustreError: 6556:0:(service.c:2344:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1865547824179840 [ 3118.062034] LustreError: 6556:0:(service.c:2344:ptlrpc_server_handle_req_in()) Skipped 2 previous similar messages [ 3122.658757] Lustre: 8439:0:(service.c:1615:ptlrpc_at_send_early_reply()) @@@ Could not add any time (5/5), not sending early reply req@ffff89d889cc6680 x1865547803117568/t0(0) o4->f862fea0-616f-46e3-9fec-d02af675c125@192.168.202.10@tcp:40/0 lens 488/448 e 1 to 0 dl 1779128095 ref 2 fl Interpret:/600/0 rc 0/0 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 3123.168718] Lustre: *** cfs_fail_loc=513, val=601*** [ 3123.175367] Lustre: Skipped 33 previous similar messages [ 3123.680168] Lustre: 8438:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779128075/real 1779128075] req@ffff89d8863b9c00 x1865547824174720/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1779128091 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_000.0' uid:0 gid:0 projid:4294967295 [ 3123.716795] 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 [ 3123.730370] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3123.742908] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3123.858523] LustreError: 6557:0:(service.c:2344:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1865547824184448 [ 3134.937175] Lustre: 3652:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779128086/real 1779128086] req@ffff89d9b7838700 x1865547824179968/t0(0) o601->lustre-MDT0000-lwp-MDT0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1779128102 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [ 3134.945312] 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 [ 3134.976811] Lustre: 3652:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 3135.006192] Lustre: lustre-MDT0000: Received new LWP connection from 0@lo, keep former export from same NID [ 3135.018551] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3138.532039] LustreError: 6556:0:(service.c:2344:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1865547824190976 [ 3138.543090] LustreError: 6556:0:(service.c:2344:ptlrpc_server_handle_req_in()) Skipped 3 previous similar messages [ 3139.554034] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779128091/real 1779128091] req@ffff89d89168f480 x1865547824184448/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1779128107 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_002.0' uid:0 gid:0 projid:4294967295 [ 3139.556491] Lustre: *** cfs_fail_loc=513, val=601*** [ 3139.606531] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 3139.606617] 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 [ 3139.610399] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3139.612316] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3139.699777] Lustre: Skipped 95 previous similar messages [ 3154.384267] Lustre: 3653:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779128106/real 1779128106] req@ffff89d88fed4000 x1865547824190976/t0(0) o601->lustre-MDT0000-lwp-MDT0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1779128122 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [ 3154.416146] 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 [ 3154.448578] Lustre: lustre-MDT0000: Received new LWP connection from 0@lo, keep former export from same NID [ 3154.459037] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3155.470491] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0001_UUID (at 0@lo) reconnecting [ 3155.474912] Lustre: Skipped 1 previous similar message [ 3186.339847] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 14:15:51 (1779128151) [ 3216.918436] Lustre: Failing over lustre-OST0000 [ 3217.029724] Lustre: server umount lustre-OST0000 complete [ 3220.972710] LustreError: lustre-OST0000-osc-MDT0000: operation ost_setattr to node 0@lo failed: rc = -107 [ 3220.982355] 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 [ 3220.993183] Lustre: Skipped 2 previous similar messages [ 3221.991863] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 3222.532531] LustreError: 42195:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3222.546497] LustreError: 42195:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 3227.112603] LustreError: 8435:0:(ldlm_lib.c:1179: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. [ 3227.130449] LustreError: 8435:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 3230.929682] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3231.307979] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3231.347524] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3232.551784] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3232.807633] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3232.809895] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3232.842252] Lustre: Skipped 2 previous similar messages [ 3238.867879] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3248.327293] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3254.655424] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3261.362646] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3267.307425] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3273.766215] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3280.257345] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3303.243932] Lustre: Failing over lustre-OST0000 [ 3303.637363] Lustre: server umount lustre-OST0000 complete [ 3304.419293] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 3304.422381] 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 [ 3304.426968] LustreError: Skipped 1 previous similar message [ 3304.443451] LustreError: 8434:0:(ldlm_lib.c:1179: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. [ 3304.443463] LustreError: 8434:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 3304.495488] Lustre: Skipped 2 previous similar messages [ 3308.005182] LustreError: 9807:0:(ldlm_lib.c:1179: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. [ 3308.040707] LustreError: 9807:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 3313.126684] LustreError: 8432:0:(ldlm_lib.c:1179: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. [ 3313.153763] LustreError: 8432:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 3315.256255] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3315.633190] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3315.679028] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3316.787544] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3316.908400] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3316.911753] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3316.923433] Lustre: Skipped 1 previous similar message [ 3323.850307] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3333.587966] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3340.133547] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3346.953877] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3353.852529] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3359.773184] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3366.021417] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3394.184845] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 14:19:19 (1779128359) [ 3427.566242] Lustre: *** cfs_fail_loc=a02, val=0*** [ 3435.515920] LustreError: 3654:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -5, flags:0x8 qsd:lustre-OST0000 qtype:usr lqe: ffff89d9af0d3080 id:60000 enforced:1 granted: 1024 pending:0 waiting:0 req:1 usage: 2048 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 3435.542561] Lustre: Failing over lustre-OST0000 [ 3435.636660] Lustre: server umount lustre-OST0000 complete [ 3437.603968] LustreError: 42197:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3437.626115] LustreError: 42197:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 3438.566489] 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 [ 3438.597350] Lustre: Skipped 1 previous similar message [ 3446.286525] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3446.836366] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3446.911039] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3447.815053] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3448.145377] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3448.146471] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3448.179407] Lustre: Skipped 1 previous similar message [ 3455.762184] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3464.670891] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3471.139239] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3479.484182] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3490.016659] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3497.232451] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3503.143509] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3548.267759] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 14:21:53 (1779128513) [ 3569.508519] LustreError: 98077:0:(qsd_reint.c:482:qsd_reint_main()) cfs_fail_timeout id a03 sleeping for 10000ms [ 3569.515877] LustreError: 98077:0:(qsd_reint.c:482:qsd_reint_main()) Skipped 5 previous similar messages [ 3571.412582] Lustre: Failing over lustre-MDT0000 [ 3572.026355] Lustre: server umount lustre-MDT0000 complete [ 3572.193043] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3572.204182] 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 [ 3572.217970] LustreError: 6559:0:(ldlm_lib.c:1179: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. [ 3572.243323] LustreError: 6559:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 3575.155904] LustreError: 98077:0:(qsd_reint.c:482:qsd_reint_main()) cfs_fail_timeout interrupted [ 3575.170986] LustreError: 98077:0:(qsd_reint.c:482:qsd_reint_main()) Skipped 1 previous similar message [ 3582.178583] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3582.336666] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3582.720076] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3582.773313] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3586.054429] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3586.997535] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3588.076486] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3588.091315] Lustre: Skipped 1 previous similar message [ 3588.106971] LustreError: 3651:0:(ldlm_resource.c:1180:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x2020000:0x0].0x0 (ffff89d9bd194200) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 3588.194499] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 3588.198056] Lustre: 98082:0:(qsd_reint.c:245:qsd_reint_index()) lustre-OST0001: index version for fid [0x200000005:0x100c:0x0] is 0, but index isn't empty (1) [ 3588.234849] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:142 to 0x280000401:161) [ 3588.235202] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:122 to 0x2c0000401:161) [ 3595.284432] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3693.562994] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3699.292775] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3705.035544] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3710.994476] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3716.277112] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3748.532523] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 14:25:13 (1779128713) [ 3770.518866] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3778.027867] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3819.595076] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 14:26:24 (1779128784) [ 3851.858862] Lustre: Failing over lustre-MDT0001 [ 3852.349792] LustreError: 25518:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3852.350627] Lustre: server umount lustre-MDT0001 complete [ 3852.370460] LustreError: 25518:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 10 previous similar messages [ 3854.313393] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3854.313886] 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 [ 3854.344607] Lustre: Skipped 4 previous similar messages [ 3866.443945] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3866.868279] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3866.942542] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3867.644648] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3871.441594] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3872.232135] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3872.253268] Lustre: Skipped 3 previous similar messages [ 3872.281495] Lustre: lustre-MDT0001: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 3872.361530] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3880.069468] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3886.856381] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3894.482542] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3901.590684] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3908.166722] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3914.050839] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3986.142191] Lustre: Failing over lustre-MDT0001 [ 3986.728098] Lustre: server umount lustre-MDT0001 complete [ 3989.986686] 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 [ 3989.990177] LustreError: 16944:0:(ldlm_lib.c:1179: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. [ 3989.992872] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3990.011569] Lustre: Skipped 2 previous similar messages [ 3990.042779] LustreError: 16944:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 3996.081602] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3997.004910] Lustre: lustre-MDT0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3997.098036] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3998.223432] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4001.797882] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4002.307058] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4002.323744] Lustre: Skipped 2 previous similar messages [ 4002.344991] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 4002.438667] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 4012.233895] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4017.977572] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4023.889578] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4029.648959] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4035.377635] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4041.983863] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4126.334914] Lustre: DEBUG MARKER: == sanity-quota test 7f: Quota reintegration automatically ========================================================== 14:31:31 (1779129091) [ 4137.744321] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4137.749874] Lustre: Skipped 1 previous similar message [ 4144.231877] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4144.233777] LustreError: 41957:0:(qsd_reint.c:627:qqi_reint_delayed()) lustre-OST0000: Delaying reintegration for qtype:0 until pending updates are flushed. [ 4199.394353] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4199.409668] Lustre: Skipped 2 previous similar messages [ 4199.434032] Lustre: 114245:0:(qsd_reint.c:245:qsd_reint_index()) lustre-MDT0001: index version for fid [0x200000005:0x1005:0x0] is 0, but index isn't empty (1) [ 4227.492607] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 14:33:12 (1779129192) [ 4419.454474] Lustre: DEBUG MARKER: == sanity-quota test 9: Block limit larger than 4GB (b10707) ========================================================== 14:36:24 (1779129384) [ 4421.701890] Lustre: DEBUG MARKER: OST0_SIZE: 3604220 required: 4900000 [ 4431.099949] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 14:36:35 (1779129395) [ 4476.463288] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 14:37:21 (1779129441) [ 4521.630472] Lustre: DEBUG MARKER: == sanity-quota test 12a: Block quota rebalancing ======== 14:38:06 (1779129486) [ 4591.581236] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 14:39:16 (1779129556) [ 4742.230824] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 14:41:47 (1779129707) [ 4807.030833] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 14:42:51 (1779129771) [ 4828.069094] Lustre: Failing over lustre-OST0000 [ 4828.252884] Lustre: server umount lustre-OST0000 complete [ 4829.666700] 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 [ 4829.688373] LustreError: 9807:0:(ldlm_lib.c:1179: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. [ 4829.699821] LustreError: 9807:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 4841.581064] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4841.883710] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4841.926709] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4842.496086] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 4843.714808] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 4843.716088] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4843.737485] Lustre: Skipped 2 previous similar messages [ 4847.818594] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4882.277214] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 14:44:07 (1779129847) [ 4910.153842] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 14:44:35 (1779129875) [ 4933.405525] Lustre: lustre-MDT0001: Client f862fea0-616f-46e3-9fec-d02af675c125 (at 192.168.202.10@tcp) reconnecting [ 4957.674777] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 14:45:22 (1779129922) [ 4959.350322] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 4961.617222] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 14:45:26 (1779129926) [ 4985.240458] Lustre: *** cfs_fail_loc=a04, val=37*** [ 4985.274876] LustreError: 41959:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr lqe: ffff89d9af108c00 id:60000 enforced:1 granted: 0 pending:0 waiting:1056 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 4986.388067] Lustre: *** cfs_fail_loc=a04, val=37*** [ 4986.390676] LustreError: 115879:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr lqe: ffff89d9af108c00 id:60000 enforced:1 granted: 0 pending:0 waiting:1056 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 5048.658670] Lustre: *** cfs_fail_loc=a04, val=11*** [ 5051.803274] Lustre: *** cfs_fail_loc=a04, val=11*** [ 5051.806716] Lustre: Skipped 1 previous similar message [ 5118.095970] Lustre: *** cfs_fail_loc=a04, val=110*** [ 5184.057392] Lustre: *** cfs_fail_loc=a04, val=107*** [ 5184.059566] Lustre: Skipped 2 previous similar messages [ 5271.226808] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 14:50:35 (1779130235) [ 5285.733118] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5292.186723] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 5301.373322] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5303.748127] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5306.247522] Lustre: Failing over lustre-MDT0000 [ 5306.633910] LustreError: 16944:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5306.648064] LustreError: 16944:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 5306.751137] Lustre: server umount lustre-MDT0000 complete [ 5307.360729] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5323.234805] Lustre: 3652:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779130275/real 1779130275] req@ffff89d9a061ca80 x1865547826697344/t0(0) o400->MGC192.168.202.110@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1779130291 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5323.257519] Lustre: 3652:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 5323.262280] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5331.955874] LDISKFS-fs (dm-0): 7 truncates cleaned up [ 5331.959245] LDISKFS-fs (dm-0): recovery complete [ 5331.981642] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5333.154094] LustreError: 140669:0:(import.c:339:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 5333.178787] LustreError: 140669:0:(import.c:363:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff89d988938000 x1865547826703104/t0(0) o250->MGC192.168.202.110@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1779130301 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5333.210425] LustreError: 140669:0:(import.c:373:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 5333.869483] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5333.923681] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5336.066033] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5339.190416] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 5339.210100] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5339.248983] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:651 to 0x280000401:673) [ 5339.250796] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:647 to 0x2c0000401:673) [ 5348.256652] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5350.025736] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5356.724176] Lustre: DEBUG MARKER: (dd_pid=128086, time=0, timeout=600) [ 5389.854686] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5397.501594] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 5406.978415] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5408.915563] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5411.023504] Lustre: Failing over lustre-MDT0000 [ 5411.506728] Lustre: server umount lustre-MDT0000 complete [ 5412.900410] LustreError: 6553:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5412.937480] LustreError: 6553:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 34 previous similar messages [ 5415.905400] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5415.913718] 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 [ 5415.926852] Lustre: Skipped 6 previous similar messages [ 5431.266118] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779130383/real 1779130383] req@ffff89d895b85180 x1865547826764032/t0(0) o400->MGC192.168.202.110@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1779130399 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5431.289629] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5436.652485] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 5436.659509] LDISKFS-fs (dm-0): recovery complete [ 5436.691128] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5441.918585] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5441.988717] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5443.165468] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5447.155205] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5447.171343] Lustre: Skipped 5 previous similar messages [ 5447.189669] LustreError: 3651:0:(ldlm_resource.c:1180:ldlm_resource_complain()) lustre-MDT0000-lwp-MDT0001: namespace resource [0x200000006:0x10000:0x0].0x0 (ffff89d985c38600) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 5447.232796] LustreError: 3651:0:(ldlm_resource.c:1180:ldlm_resource_complain()) Skipped 5 previous similar messages [ 5447.322269] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 5447.436296] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:675 to 0x280000401:705) [ 5447.438019] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:647 to 0x2c0000401:705) [ 5447.651552] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5457.233310] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5459.001541] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5465.169952] Lustre: DEBUG MARKER: (dd_pid=130464, time=0, timeout=600) [ 5511.114318] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 14:54:36 (1779130476) [ 5566.061255] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 14:55:30 (1779130530) [ 5594.240968] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 5606.956580] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 5608.973497] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 5610.753978] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 5613.252884] Lustre: DEBUG MARKER: Set quota for 1 times [ 5616.921328] Lustre: DEBUG MARKER: Set quota for 2 times [ 5620.817811] Lustre: DEBUG MARKER: Set quota for 3 times [ 5624.903818] Lustre: DEBUG MARKER: Set quota for 4 times [ 5628.575152] Lustre: DEBUG MARKER: Set quota for 5 times [ 5632.242981] Lustre: DEBUG MARKER: Set quota for 6 times [ 5635.780285] Lustre: DEBUG MARKER: Set quota for 7 times [ 5639.492628] Lustre: DEBUG MARKER: Set quota for 8 times [ 5693.896187] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 14:57:38 (1779130658) [ 5713.378797] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5713.398264] Lustre: Skipped 3 previous similar messages [ 5716.931521] Lustre: server umount lustre-MDT0000 complete [ 5718.512205] LustreError: 6554:0:(ldlm_lib.c:1179: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. [ 5718.536737] LustreError: 6554:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 32 previous similar messages [ 5721.102639] LustreError: 9508:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779130689 with bad export cookie 12834121344675546056 [ 5721.105604] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5721.110565] LustreError: 9508:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 5721.534380] Lustre: server umount lustre-MDT0001 complete [ 5736.945190] Lustre: server umount lustre-OST0000 complete [ 5739.808193] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779130691/real 1779130691] req@ffff89d89083dc00 x1865547826970112/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779130707 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5741.412748] Lustre: server umount lustre-OST0001 complete [ 5760.426064] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 5773.563264] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5774.167742] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5780.199442] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5789.778223] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5790.154991] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5795.066509] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5798.674718] Lustre: 153529:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5807.865110] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5808.576579] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5816.416662] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5819.892216] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:708 to 0x280000401:737) [ 5826.209727] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5826.549839] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5831.682085] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:707 to 0x2c0000401:737) [ 5831.798055] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:97) [ 5833.303651] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5842.187746] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5845.861871] Lustre: 155369:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5866.979563] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5866.997063] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5872.618705] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5872.629071] Lustre: Skipped 7 previous similar messages [ 5873.211622] Lustre: server umount lustre-MDT0000 complete [ 5877.657428] LustreError: 152388:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779130845 with bad export cookie 12834121344675553098 [ 5877.670883] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5877.676126] LustreError: 152388:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 5877.730045] LustreError: 152404:0:(ldlm_lib.c:1179: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. [ 5877.733049] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5877.754699] LustreError: 152404:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 10 previous similar messages [ 5877.768326] Lustre: Skipped 1 previous similar message [ 5878.124880] Lustre: server umount lustre-MDT0001 complete [ 5885.353332] Lustre: server umount lustre-OST0000 complete [ 5889.195613] Lustre: server umount lustre-OST0001 complete [ 5905.437964] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 5916.629914] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5917.494048] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5921.573989] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5930.805789] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5935.491096] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5938.566599] Lustre: 159074:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5946.233303] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5953.224292] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5962.143439] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5962.464624] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5962.470573] Lustre: Skipped 2 previous similar messages [ 5963.525085] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:708 to 0x280000401:769) [ 5963.555653] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:707 to 0x2c0000401:769) [ 5963.691098] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:129) [ 5969.356216] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5976.417619] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5979.740655] Lustre: 160916:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5989.708873] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 15:02:35 (1779130955) [ 5991.133952] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 6144 [ 5992.600835] Lustre: DEBUG MARKER: run for 4MB test file [ 6004.585156] Lustre: DEBUG MARKER: User quota (limit: 4 MB) [ 6011.592028] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 6013.858711] Lustre: DEBUG MARKER: Write half of file [ 6017.045447] Lustre: DEBUG MARKER: Write out of block quota ... [ 6019.684609] Lustre: DEBUG MARKER: Step1: done [ 6021.369404] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 6022.909576] Lustre: DEBUG MARKER: Step2: done [ 6052.876527] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 61440 [ 6054.394131] Lustre: DEBUG MARKER: run for 40MB test file [ 6066.428693] Lustre: DEBUG MARKER: User quota (limit: 40 MB) [ 6072.494508] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 6074.271829] Lustre: DEBUG MARKER: Write half of file [ 6077.417819] Lustre: DEBUG MARKER: Write out of block quota ... [ 6080.392950] Lustre: DEBUG MARKER: Step1: done [ 6081.821954] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 6083.458788] Lustre: DEBUG MARKER: Step2: done [ 6136.609688] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 15:05:01 (1779131101) [ 6183.581763] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 15:05:49 (1779131149) [ 6221.557989] Lustre: DEBUG MARKER: Write... [ 6224.769300] Lustre: DEBUG MARKER: Write out of block quota ... [ 6276.303126] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 15:07:21 (1779131241) [ 6282.561325] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 15:07:28 (1779131248) [ 6291.812710] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 15:07:37 (1779131257) [ 6300.026801] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 15:07:45 (1779131265) [ 6307.204594] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 15:07:52 (1779131272) [ 6360.873388] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 6498.859938] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 6646.555630] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 15:13:31 (1779131611) [ 6695.786056] Lustre: DEBUG MARKER: Restart... [ 6701.030622] 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 [ 6701.042461] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6701.058316] Lustre: Skipped 15 previous similar messages [ 6701.065180] Lustre: Skipped 1 previous similar message [ 6706.149651] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6706.160691] Lustre: Skipped 5 previous similar messages [ 6706.925304] Lustre: server umount lustre-MDT0000 complete [ 6711.249742] LustreError: 157948:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779131679 with bad export cookie 12834121344675555401 [ 6711.252123] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6711.259348] LustreError: 157948:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [ 6711.274640] LustreError: 157963:0:(ldlm_lib.c:1179: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. [ 6711.298016] LustreError: 157963:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 6711.302776] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 6711.326343] Lustre: Skipped 1 previous similar message [ 6711.739779] Lustre: server umount lustre-MDT0001 complete [ 6718.162165] Lustre: server umount lustre-OST0000 complete [ 6721.816043] Lustre: server umount lustre-OST0001 complete [ 6738.904804] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 6750.246822] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6750.965106] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6755.379207] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6763.745820] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6764.130247] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6768.959813] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6772.558557] Lustre: 185314:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 6780.062149] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6780.596315] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6788.239301] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6795.256065] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:780 to 0x280000401:801) [ 6801.469140] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6807.536613] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:778 to 0x2c0000401:801) [ 6807.539325] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:161) [ 6810.587428] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6819.384084] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6823.895835] Lustre: 187151:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 6897.083191] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 15:17:42 (1779131862) [ 6950.138235] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 15:18:34 (1779131914) [ 8585.299181] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 15:45:50 (1779133550) [ 8593.678099] Lustre: server umount lustre-MDT0000 complete [ 8595.427606] 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 [ 8595.432450] LustreError: 186917:0:(ldlm_lib.c:1179: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. [ 8595.439365] Lustre: Skipped 6 previous similar messages [ 8595.473111] LustreError: 186917:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 12 previous similar messages [ 8597.144770] LustreError: 191392:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779133565 with bad export cookie 12834121344675564522 [ 8597.145303] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8597.156022] LustreError: 191392:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 8597.422250] Lustre: server umount lustre-MDT0001 complete [ 8612.164286] Lustre: server umount lustre-OST0000 complete [ 8626.580151] Lustre: server umount lustre-OST0001 complete [ 8643.941700] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 8655.276627] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8655.786910] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8655.790811] Lustre: Skipped 1 previous similar message [ 8660.976324] LustreError: 194616:0:(ldlm_lib.c:1179: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. [ 8660.996056] LustreError: 194616:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 8661.399979] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8672.949036] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8673.707643] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 8677.781453] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8681.527724] Lustre: 195726:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 8690.782370] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 8691.306976] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 8697.571877] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8700.532513] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:5804 to 0x280000401:5825) [ 8706.574339] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 8712.200477] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:5802 to 0x2c0000401:5825) [ 8712.208553] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:193) [ 8712.932394] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8720.833552] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8725.459713] Lustre: 197563:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 8754.156697] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 15:48:39 (1779133719) [ 8783.706822] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 15:49:08 (1779133748) [ 8813.139721] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 15:49:37 (1779133777) [ 8851.698593] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 15:50:16 (1779133816) [ 8894.451191] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 15:50:59 (1779133859) [ 8967.941618] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 15:52:12 (1779133932) [ 9001.647594] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 15:52:47 (1779133967) [ 9076.083696] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 15:54:01 (1779134041) [ 9082.148446] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9082.151975] Lustre: Skipped 2 previous similar messages [ 9084.155926] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9084.160931] Lustre: Skipped 111 previous similar messages [ 9088.166475] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9088.169285] Lustre: Skipped 219 previous similar messages [ 9096.221136] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9096.226461] Lustre: Skipped 443 previous similar messages [ 9112.289871] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9112.294261] Lustre: Skipped 733 previous similar messages [ 9144.381439] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9144.387280] Lustre: Skipped 1213 previous similar messages [ 9208.394756] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9208.402327] Lustre: Skipped 2875 previous similar messages [ 9517.676635] Lustre: *** cfs_fail_loc=a08, val=0*** [ 9517.691438] Lustre: Skipped 2411 previous similar messages [ 9517.695443] Lustre: *** cfs_fail_loc=a08, val=0*** [ 9661.921482] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 9661.924295] 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 [ 9661.947880] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 9665.696544] Lustre: server umount lustre-MDT0000 complete [ 9667.559146] LustreError: 194616:0:(ldlm_lib.c:1179: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. [ 9667.596092] LustreError: 194616:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 10 previous similar messages [ 9670.255191] LustreError: 197565:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779134638 with bad export cookie 12834121344677341535 [ 9670.276235] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 9670.278744] LustreError: 197565:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 9672.723367] 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 [ 9672.730179] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 9672.748322] Lustre: Skipped 4 previous similar messages [ 9672.766276] Lustre: Skipped 4 previous similar messages [ 9675.684075] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 9676.800284] Lustre: server umount lustre-MDT0001 complete [ 9682.046266] Lustre: server umount lustre-OST0000 complete [ 9686.403144] Lustre: server umount lustre-OST0001 complete [ 9694.834151] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [ 9704.907434] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 9762.365350] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 9775.032934] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 9775.329591] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 9775.380337] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 9775.513236] Lustre: lustre-MDT0000: new disk, initializing [ 9775.695853] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 9775.701536] Lustre: Skipped 1 previous similar message [ 9775.719106] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 9780.232083] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9792.717698] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 9792.811437] Lustre: 214293:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 9792.838710] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 9792.845292] Lustre: Skipped 1 previous similar message [ 9792.939742] Lustre: lustre-MDT0001: new disk, initializing [ 9793.068672] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 9793.111283] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 9793.130095] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 9799.212768] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9805.511857] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 9812.880353] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 9813.068876] Lustre: lustre-OST0000: new disk, initializing [ 9813.071334] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 9813.075047] Lustre: 215892:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 9813.150655] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 9814.892437] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 9814.904576] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 9815.038022] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 9819.598729] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9834.128755] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 9834.324511] Lustre: lustre-OST0001: new disk, initializing [ 9834.329849] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 9834.337062] Lustre: 216744:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 9834.442450] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 9836.337175] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 9836.349807] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 9836.508589] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 9843.040037] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9854.561283] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 9858.763751] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 9888.367769] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 16:07:33 (1779134853) [ 9896.492400] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 16:07:41 (1779134861) [ 9932.049841] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 16:08:16 (1779134896) [ 9986.532770] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 16:09:11 (1779134951) [10012.158162] Lustre: DEBUG MARKER: rename directory return 255 [10052.661253] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 16:10:17 (1779135017) [10081.595368] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 16:10:46 (1779135046) [10118.654634] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 16:11:22 (1779135082) [10266.642526] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 16:13:52 (1779135232) [10295.622661] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 16:14:19 (1779135259) [10335.792837] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 16:15:00 (1779135300) [10493.279155] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 16:17:37 (1779135457) [10502.114497] 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 [10502.116729] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10502.158728] Lustre: Skipped 3 previous similar messages [10502.184399] Lustre: Skipped 4 previous similar messages [10506.612941] Lustre: server umount lustre-MDT0000 complete [10507.235775] LustreError: 214305:0:(ldlm_lib.c:1179: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. [10507.266165] LustreError: 214305:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [10510.483497] LustreError: 214286:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779135478 with bad export cookie 12834121344677713739 [10510.488453] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10510.495670] LustreError: 214286:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [10510.874415] Lustre: server umount lustre-MDT0001 complete [10525.583648] Lustre: server umount lustre-OST0000 complete [10528.736463] Lustre: 3655:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779135480/real 1779135480] req@ffff89d9bf9d1c00 x1865547838160384/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779135496 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [10528.786991] 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 [10531.235516] Lustre: server umount lustre-OST0001 complete [10561.842521] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [10574.088412] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10574.738189] LustreError: 233826:0:(ldlm_lib.c:1179: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. [10574.837265] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10574.870963] 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 [10579.938575] LustreError: 233827:0:(ldlm_lib.c:1179: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. [10580.071803] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10589.160452] LustreError: 233826:0:(ldlm_lib.c:1179: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. [10589.179033] LustreError: 233826:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [10589.448625] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10589.741809] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [10589.751369] 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 [10594.365706] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10597.519297] Lustre: 234936:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10604.456612] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10604.727086] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [10604.733420] 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 [10610.919945] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10614.946153] LustreError: 235290:0:(ldlm_lib.c:1179: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. [10619.066136] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:20 to 0x280000401:65) [10619.590613] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10619.877369] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [10619.896510] 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 [10625.024869] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:65) [10627.081472] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10634.465799] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10637.960319] Lustre: 236778:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10645.798627] LustreError: 236057:0:(osd_handler.c:3426:osd_quota_transfer()) lustre-MDT0000: quota transfer failed. Is project enforcement enabled on the ldiskfs filesystem? rc = -95 [10650.605831] 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 [10650.607587] LustreError: lustre-MDT0000-lwp-MDT0001: operation quota_acquire to node 0@lo failed: rc = -107 [10650.612170] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10650.617954] Lustre: Skipped 2 previous similar messages [10650.637642] LustreError: Skipped 1 previous similar message [10655.716500] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10655.732420] Lustre: Skipped 6 previous similar messages [10656.880156] Lustre: server umount lustre-MDT0000 complete [10660.810267] LustreError: 233806:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779135628 with bad export cookie 12834121344677762753 [10660.817491] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10660.819204] LustreError: 233806:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [10660.851279] LustreError: 233823:0:(ldlm_lib.c:1179: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. [10660.854333] 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 [10660.871629] LustreError: 233823:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [10660.905757] Lustre: Skipped 1 previous similar message [10660.909339] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [10660.913763] Lustre: Skipped 1 previous similar message [10661.327874] Lustre: server umount lustre-MDT0001 complete [10666.976503] LustreError: 3655:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff89d893ef7480 x1865547838212224/t0(0) o601->lustre-MDT0000-lwp-OST0000@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 [10666.998900] LustreError: 3655:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -5, flags:0x8 qsd:lustre-OST0000 qtype:grp lqe: ffff89d895ad0180 id:0 enforced:0 granted: 0 pending:0 waiting:0 req:1 usage: 1516 qunit:0 qtune:0 edquot:0 default:no revoke:0 [10667.011605] LustreError: 3655:0:(qsd_handler.c:298:qsd_req_completion()) Skipped 1 previous similar message [10667.725322] Lustre: server umount lustre-OST0000 complete [10671.858289] Lustre: server umount lustre-OST0001 complete [10695.553403] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [10708.122471] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10708.848661] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10714.263565] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10723.717741] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10728.070267] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10731.552537] Lustre: 240274:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10739.351826] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10746.878811] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10748.910557] LustreError: 240628:0:(ldlm_lib.c:1179: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. [10748.943167] LustreError: 240628:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [10754.048449] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:20 to 0x280000401:97) [10759.167032] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10759.425330] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [10759.444316] Lustre: Skipped 2 previous similar messages [10764.785236] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:67 to 0x2c0000401:97) [10767.067470] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10776.006846] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10780.525995] Lustre: 242117:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10813.088921] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 16:22:58 (1779135778) [10862.949059] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [10864.748679] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 16:23:50 (1779135830) [10888.803992] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [10890.747301] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 16:24:15 (1779135855) [10934.903045] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [10937.445835] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 16:25:02 (1779135902) [10983.065462] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 16:25:47 (1779135947) [10998.766500] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [11006.181210] Lustre: 248828:0:(qsd_reint.c:245:qsd_reint_index()) lustre-OST0000: index version for fid [0x200000005:0x1007:0x0] is 0, but index isn't empty (1) [11006.206874] Lustre: 248828:0:(qsd_reint.c:245:qsd_reint_index()) Skipped 1 previous similar message [11012.090944] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [11019.441967] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [11024.330656] Lustre: DEBUG MARKER: Write... [11047.080870] LustreError: 250141:0:(mgs_handler.c:1140:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [11054.321988] Lustre: DEBUG MARKER: Write... [11069.423020] Lustre: DEBUG MARKER: Write... [11156.941549] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 16:28:41 (1779136121) [11187.549441] LustreError: 254255:0:(mgs_handler.c:1140:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [11237.950814] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 16:30:02 (1779136202) [11265.282847] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [11267.160295] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [11353.830250] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 16:31:58 (1779136318) [11409.226020] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 16:32:54 (1779136374) [11452.860787] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 16:33:38 (1779136418) [11466.516513] Lustre: DEBUG MARKER: User quota (block hardlimit:100 MB) [11492.483771] Lustre: DEBUG MARKER: Write... [11494.880687] Lustre: DEBUG MARKER: Write out of block quota ... [11586.612690] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 16:35:51 (1779136551) [11599.774616] Lustre: DEBUG MARKER: User quota (block hardlimit:1000 MB) [11628.838246] LustreError: 239409:0:(qmt_entry.c:552: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 [11691.614778] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 16:37:37 (1779136657) [11703.067679] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [11721.008896] Lustre: DEBUG MARKER: Write... [11722.609682] Lustre: DEBUG MARKER: Write out of block quota ... [11774.524541] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 16:38:59 (1779136739) [11801.332963] Lustre: DEBUG MARKER: set to use default quota [11802.892905] Lustre: DEBUG MARKER: set default quota [11804.350835] Lustre: DEBUG MARKER: get default quota [11810.137273] Lustre: DEBUG MARKER: Test not out of quota [11814.504182] Lustre: DEBUG MARKER: Test out of quota [11823.886448] Lustre: DEBUG MARKER: Increase default quota [11848.908155] Lustre: DEBUG MARKER: Set quota to override default quota [11849.006441] LustreError: 239157:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:20480 soft:20480 granted:45056 time:1779741616 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11859.705524] Lustre: DEBUG MARKER: Set to use default quota again [11881.447879] Lustre: DEBUG MARKER: Cleanup [11942.331632] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 16:41:47 (1779136907) [11966.069418] Lustre: DEBUG MARKER: set default quota for qpool1 [11967.911739] Lustre: DEBUG MARKER: Write from user that hasn't lqe [12021.103627] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 16:43:06 (1779136986) [12108.274619] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 16:44:33 (1779137073) [12183.103454] Lustre: DEBUG MARKER: Write... [12185.873762] Lustre: DEBUG MARKER: Write out of block quota ... [12292.681450] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 16:47:38 (1779137258) [12328.312381] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 16:48:13 (1779137293) [12336.178725] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 16:48:21 (1779137301) [12373.296737] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 16:48:58 (1779137338) [12415.361704] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 16:49:40 (1779137380) [12437.523407] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 16:50:02 (1779137402) [12468.021089] Lustre: *** cfs_fail_loc=a06, val=0*** [12468.022808] Lustre: Skipped 3 previous similar messages [12468.625783] LustreError: 239159:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:10240 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [12474.371958] Lustre: Failing over lustre-OST0001 [12474.560742] Lustre: server umount lustre-OST0001 complete [12474.855535] LustreError: lustre-OST0001-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [12474.864710] Lustre: lustre-OST0001-osc-MDT0000: Connection to lustre-OST0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [12474.886551] Lustre: Skipped 2 previous similar messages [12474.896924] LustreError: 240630:0:(ldlm_lib.c:1179: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. [12474.935057] LustreError: 240630:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [12484.590552] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [12484.948743] Lustre: lustre-OST0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12485.001538] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [12486.373913] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [12486.668891] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [12486.668944] Lustre: lustre-OST0001-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12486.709419] Lustre: Skipped 3 previous similar messages [12492.151111] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12544.177797] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 16:51:49 (1779137509) [12559.513329] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [12568.149279] LustreError: 293271:0:(qmt_pool.c:1399:qmt_pool_recalc()) cfs_fail_timeout id a07 sleeping for 10000ms [12571.616344] LustreError: 3654:0:(client.c:1380:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff89d8935cdf80 x1865547839835776/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 [12571.640147] LustreError: lustre-MDT0000-lwp-MDT0001: operation quota_acquire to node 0@lo failed: rc = -107 [12571.647128] LustreError: 3654:0:(client.c:1380:ptlrpc_import_delay_req()) Skipped 1 previous similar message [12571.647590] LustreError: 3654:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -5, flags:0x8 qsd:lustre-MDT0000 qtype:usr lqe: ffff89d889883380 id:0 enforced:0 granted: 0 pending:0 waiting:0 req:1 usage: 320 qunit:0 qtune:0 edquot:0 default:no revoke:0 [12571.657654] 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 [12571.660977] LustreError: Skipped 1 previous similar message [12571.717547] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [12574.756901] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.10@tcp (stopping) [12574.767705] Lustre: Skipped 4 previous similar messages [12577.250383] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [12577.263805] Lustre: Skipped 3 previous similar messages [12578.232132] LustreError: 293271:0:(qmt_pool.c:1399:qmt_pool_recalc()) cfs_fail_timeout id a07 awake [12578.890947] Lustre: server umount lustre-MDT0000 complete [12579.832694] LustreError: 239158:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [12579.845552] LustreError: 239158:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [12588.011794] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [12588.208923] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [12588.436743] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [12588.493771] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:129) [12588.507442] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:112 to 0x280000401:129) [12593.657158] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [12593.668144] Lustre: Skipped 1 previous similar message [12593.861665] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12631.731288] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 16:53:16 (1779137596) [12662.069646] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 16:53:46 (1779137626) [12690.639648] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 16:54:15 (1779137655) [12740.659606] Lustre: *** cfs_fail_loc=a08, val=0*** [12740.665391] Lustre: Skipped 6 previous similar messages [12740.669671] Lustre: *** cfs_fail_loc=a08, val=0*** [12740.673997] Lustre: Skipped 15 previous similar messages [12840.707484] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 16:56:45 (1779137805) [12871.399518] LustreError: 239159:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:3072 soft:0 granted:3072 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [12925.091873] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 16:58:10 (1779137890) [12989.951172] LustreError: 239158:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1779742757 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [13134.728314] LustreError: 239156:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1779742902 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [13280.094442] LustreError: 246166:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:1000 enforced:1 hard:2048 soft:2048 granted:16384 time:1779743048 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [13389.660534] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 17:05:54 (1779138354) [13397.615351] Lustre: *** cfs_fail_loc=a09, val=0*** [13397.617271] Lustre: Skipped 1 previous similar message [13468.132234] 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 [13468.136381] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13468.166195] Lustre: Skipped 6 previous similar messages [13468.190286] Lustre: Skipped 3 previous similar messages [13469.931552] Lustre: server umount lustre-MDT0000 complete [13470.772472] LustreError: 240344:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13470.803646] LustreError: 240344:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [13475.842754] LustreError: 239157:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.202.10@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13475.862606] LustreError: 239157:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [13479.541657] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13479.701681] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13480.097575] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13480.175663] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:132 to 0x280000401:161) [13480.175992] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:161) [13484.864480] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13485.551177] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13485.577167] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [13485.589735] Lustre: Skipped 4 previous similar messages [13503.958636] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 17:07:49 (1779138469) [13505.655842] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [13508.161727] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 17:07:53 (1779138473) [13530.832122] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 17:08:16 (1779138496) [13548.069647] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 17:08:33 (1779138513) [13568.348205] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 17:08:53 (1779138533) [13587.940556] 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 [13587.942436] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13587.942558] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [13587.942564] LustreError: Skipped 1 previous similar message [13587.968691] Lustre: Skipped 2 previous similar messages [13588.012886] Lustre: Skipped 3 previous similar messages [13590.898627] Lustre: server umount lustre-MDT0000 complete [13593.068519] LustreError: 303085:0:(ldlm_lib.c:1179: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. [13593.086097] LustreError: 303085:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [13595.927506] LustreError: 243238:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779138563 with bad export cookie 12834121344678867213 [13595.935821] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13595.940891] LustreError: 243238:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [13598.180899] 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 [13598.186101] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [13598.213765] Lustre: Skipped 2 previous similar messages [13600.226218] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [13600.235701] Lustre: Skipped 2 previous similar messages [13602.645616] Lustre: server umount lustre-MDT0001 complete [13613.818962] Lustre: server umount lustre-OST0000 complete [13624.442217] Lustre: server umount lustre-OST0001 complete [13631.545983] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [13641.114712] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [13698.450129] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13699.059961] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [13699.146322] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [13699.264767] Lustre: lustre-MDT0000: new disk, initializing [13699.398730] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13699.430357] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [13705.142832] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13713.186500] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [13721.649833] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13722.005637] Lustre: lustre-OST0000: new disk, initializing [13722.009996] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [13722.022591] Lustre: Skipped 1 previous similar message [13722.029317] Lustre: 311678:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13722.145797] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [13723.164604] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [13723.197514] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [13723.269433] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [13729.043875] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13736.745449] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [13743.599607] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13743.742713] Lustre: lustre-OST0001: new disk, initializing [13743.745182] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [13743.750242] Lustre: 312620:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13743.812174] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [13745.412665] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [13745.423283] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [13745.458053] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [13750.615990] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13759.653980] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid [13775.068531] Lustre: server umount lustre-MDT0000 complete [13787.526848] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13787.880705] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13788.267113] 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 [13788.349491] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13792.417139] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779138744/real 1779138744] req@ffff89d88182f100 x1865547841265920/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779138760 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [13793.764393] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [13794.374413] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13797.861484] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779138749/real 1779138749] req@ffff89d88182e300 x1865547841266304/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779138765 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [13797.900342] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [13801.296611] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [13802.976188] Lustre: 3652:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779138754/real 1779138754] req@ffff89d892fc2300 x1865547841266688/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779138770 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [13803.796238] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [13806.017325] LustreError: 314187:0:(qmt_entry.c:1166:qmt_map_lge_idx()) qmt: cannot map ostidx 1, num_used 1: rc = -22 [13809.422064] LustreError: 314187:0:(qmt_entry.c:1166:qmt_map_lge_idx()) qmt: cannot map ostidx 1, num_used 1: rc = -22 [13814.249115] 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 [13814.259741] Lustre: Skipped 1 previous similar message [13814.300943] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13814.308763] Lustre: Skipped 1 previous similar message [13819.988323] Lustre: server umount lustre-MDT0000 complete [13828.254201] LustreError: 310783:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779138796 with bad export cookie 12834121344678869852 [13828.262597] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13828.270586] LustreError: 310783:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [13828.609243] Lustre: server umount lustre-OST0000 complete [13832.970381] Lustre: server umount lustre-OST0001 complete [13854.939774] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [13863.764285] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [13912.801337] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [13925.166451] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13925.691056] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [13925.759274] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [13925.911734] Lustre: lustre-MDT0000: new disk, initializing [13926.084027] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13926.115695] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [13931.529219] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13943.742594] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13943.851656] Lustre: 318857:0:(mgs_llog.c:1437:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [13943.873401] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [13943.877954] Lustre: Skipped 1 previous similar message [13943.941235] Lustre: lustre-MDT0001: new disk, initializing [13944.042320] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [13944.048403] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [13949.484223] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13955.363935] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [13962.396712] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13962.797583] Lustre: lustre-OST0000: new disk, initializing [13962.803932] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [13962.809441] Lustre: 320454:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13962.930872] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [13962.942651] Lustre: Skipped 1 previous similar message [13964.116016] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [13964.134144] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [13964.327541] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [13971.132962] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13986.410983] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13986.708294] Lustre: lustre-OST0001: new disk, initializing [13986.719685] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [13986.734290] Lustre: 321309:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13988.238494] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [13988.262738] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [13988.468574] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [13995.074096] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14007.072542] Lustre: DEBUG MARKER: Using TIMEOUT=20 [14011.258415] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [14020.646748] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 17:16:25 (1779138985) [14040.842964] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 17:16:45 (1779139005) [14067.399303] Lustre: *** cfs_fail_loc=170c, val=0*** [14122.162616] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 17:18:07 (1779139087) [14162.401349] 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 [14162.405028] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [14162.416068] Lustre: Skipped 2 previous similar messages [14162.424338] Lustre: Skipped 5 previous similar messages [14176.224173] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [14176.597994] Lustre: server umount lustre-MDT0000 complete [14177.761553] LustreError: 318862:0:(ldlm_lib.c:1179: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. [14177.777487] LustreError: 318862:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [14189.814042] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14189.998766] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14190.445440] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [14190.453454] Lustre: Skipped 1 previous similar message [14190.548631] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:33) [14195.442708] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14195.687694] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14195.730183] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [14195.734709] Lustre: Skipped 2 previous similar messages [14205.932972] 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 [14205.935707] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14205.963756] Lustre: Skipped 2 previous similar messages [14205.967680] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [14206.012422] Lustre: Skipped 14 previous similar messages [14211.546572] Lustre: server umount lustre-MDT0000 complete [14216.163052] LustreError: 318863:0:(ldlm_lib.c:1179: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. [14216.192171] LustreError: 318863:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [14222.281058] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14222.487345] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14222.883723] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:65) [14227.764780] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14227.957538] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14235.728780] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 17:20:00 (1779139200) [14266.569484] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 17:20:30 (1779139230) [14310.807448] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 17:21:15 (1779139275) [14312.935421] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 OST is too small, skip the test [14315.507665] Lustre: DEBUG MARKER: == sanity-quota test 97a: LQA control commands =========== 17:21:20 (1779139280) [14345.745343] LustreError: 331990:0:(qmt_lqa.c:79:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-dt-lqa1: rc = -2 [14345.758798] LustreError: 331990:0:(qmt_lqa.c:84:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-md-lqa1: rc = -2 [14347.967556] Lustre: DEBUG MARKER: == sanity-quota test 97b: Check LQA internals ============ 17:21:52 (1779139312) [14370.675527] LustreError: 332886:0:(qmt_lqa.c:250:qmt_lqa_insert_range()) lustre-QMT0000: LQA range 15-31 partially overlaps with existing range 10-19: rc = -34 [14370.683928] LustreError: 332886:0:(qmt_lqa.c:669:qmt_lqa_add()) lustre-QMT0000: lqa:lqa1 can't add range 15:31: rc = -17 [14374.468311] LustreError: 333082:0:(qmt_lqa.c:825:qmt_lqa_remove()) lustre-QMT0000: lqa-md-lqa1 cannot remove range 10:19: rc = -2 [14385.295229] Lustre: DEBUG MARKER: adding 50 LQA ranges took 1s [14391.262890] Lustre: DEBUG MARKER: Removing 50 LQA ranges took 2s [14401.424664] Lustre: DEBUG MARKER: == sanity-quota test 97c: LQA lfs quota commands and MDS restart consistency ========================================================== 17:22:46 (1779139366) [14406.856868] Lustre: Failing over lustre-MDT0000 [14407.142478] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14407.145391] 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 [14407.147749] LustreError: 320461:0:(ldlm_lib.c:1179: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. [14407.171939] Lustre: Skipped 6 previous similar messages [14407.191741] LustreError: 320461:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [14407.251832] Lustre: server umount lustre-MDT0000 complete [14417.716442] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14417.963283] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14418.525479] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [14418.535556] Lustre: Skipped 1 previous similar message [14418.612973] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [14420.989488] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [14423.539077] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [14423.542830] Lustre: Skipped 6 previous similar messages [14423.564276] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [14423.595620] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:97) [14423.829726] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14430.827863] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [14440.177831] Lustre: DEBUG MARKER: == sanity-quota test 97d: LQA disk persistence using standard commands ========================================================== 17:23:25 (1779139405) [14458.258294] Lustre: Failing over lustre-MDT0000 [14458.573625] Lustre: server umount lustre-MDT0000 complete [14469.830389] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14470.082667] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14470.572978] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [14472.259331] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [14475.791078] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [14475.872884] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:129) [14477.654836] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14486.193980] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [14525.057848] Lustre: DEBUG MARKER: == sanity-quota test 98: Verify MDT retry on -EDQUOT during mkdir ========================================================== 17:24:49 (1779139489) [14529.824972] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [14532.122577] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [14536.647325] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0001-mdc-*.mds_server_uuid [14539.365277] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [14545.944444] Lustre: *** cfs_fail_loc=a02, val=0*** [14559.008357] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 14265 sec ======== 17:25:24 (1779139524) [14561.160552] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 17:25:26 (1779139526) === [14564.933401] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 17:25:30 (1779139530) === [14573.027599] 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 [14573.027715] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14573.028064] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [14573.028069] Lustre: Skipped 6 previous similar messages [14573.061599] Lustre: Skipped 6 previous similar messages [14577.030483] Lustre: server umount lustre-MDT0000 complete [14578.148736] LustreError: 320461:0:(ldlm_lib.c:1179: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. [14578.189388] LustreError: 320461:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 27 previous similar messages [14587.245569] LustreError: 318848:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1779139555 with bad export cookie 12834121344678876411 [14587.253173] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14587.253845] LustreError: 318848:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [14587.719236] Lustre: server umount lustre-MDT0001 complete [14604.704198] Lustre: 3653:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779139556/real 1779139556] req@ffff89d983e06a00 x1865547841678208/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779139572 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14604.752033] Lustre: 3653:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 1 previous similar message [14608.246984] Lustre: server umount lustre-OST0000 complete [14608.736222] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779139560/real 1779139560] req@ffff89d9bd212680 x1865547841678464/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779139576 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14609.904163] Lustre: 3653:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779139561/real 1779139561] req@ffff89d892fa7480 x1865547841678720/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779139577 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14613.920098] Lustre: 3654:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779139565/real 1779139565] req@ffff89d892fa6680 x1865547841679104/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779139581 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14618.080655] Lustre: 3655:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1779139570/real 1779139570] req@ffff89d886223800 x1865547841679360/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1779139586 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14619.148835] Lustre: server umount lustre-OST0001 complete [14642.473851] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing unload_modules_local [14646.739712] Key type lgssc unregistered [14647.057703] LNet: 341643:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [14647.077707] LNetError: 341643:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [14647.107487] LNet: Removed LNI 192.168.202.110@tcp [14648.723048] Key type .llcrypt unregistered [14648.736334] Key type ._llcrypt unregistered