[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 521825785 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 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, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001011] APIC: Switch to symmetric I/O mode setup [ 0.003375] x2apic enabled [ 0.004010] Switched APIC routing to physical x2apic. [ 0.005014] kvm-guest: setup PV IPIs [ 0.007788] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008000] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008013] pid_max: default: 32768 minimum: 301 [ 0.010126] LSM: Security Framework initializing [ 0.012023] Yama: becoming mindful. [ 0.013049] SELinux: Initializing. [ 0.014083] *** VALIDATE selinux *** [ 0.022163] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027369] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028112] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029101] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030103] *** VALIDATE tmpfs *** [ 0.031323] *** VALIDATE proc *** [ 0.032250] *** VALIDATE cgroup *** [ 0.033006] *** VALIDATE cgroup2 *** [ 0.034245] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.035130] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.036005] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037026] Spectre V2 : User space: Vulnerable [ 0.038005] Speculative Store Bypass: Vulnerable [ 0.041365] debug: unmapping init [mem 0xffffffffa0859000-0xffffffffa0860fff] [ 0.044154] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.045693] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.046027] ... version: 2 [ 0.047011] ... bit width: 48 [ 0.048011] ... generic registers: 4 [ 0.049011] ... value mask: 0000ffffffffffff [ 0.050015] ... max period: 00007fffffffffff [ 0.051014] ... fixed-purpose events: 3 [ 0.052012] ... event mask: 000000070000000f [ 0.054234] rcu: Hierarchical SRCU implementation. [ 0.056452] smp: Bringing up secondary CPUs ... [ 0.057570] x86: Booting SMP configuration: [ 0.058023] .... node #0, CPUs: #1 #2 #3 [ 0.062121] smp: Brought up 1 node, 4 CPUs [ 0.064015] smpboot: Max logical packages: 1 [ 0.065015] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.203535] node 0 deferred pages initialised in 135ms [ 0.206110] devtmpfs: initialized [ 0.207327] x86/mm: Memory block size: 128MB [ 0.210000] gcov: version magic: 0x41383552 [ 0.213366] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.217104] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.220423] pinctrl core: initialized pinctrl subsystem [ 0.222193] [ 0.222631] ************************************************************* [ 0.225019] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.227016] ** ** [ 0.229019] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.232018] ** ** [ 0.235019] ** This means that this kernel is built to expose internal ** [ 0.237016] ** IOMMU data structures, which may compromise security on ** [ 0.240018] ** your system. ** [ 0.242016] ** ** [ 0.245019] ** If you see this message and you are not debugging the ** [ 0.248022] ** kernel, report this immediately to your vendor! ** [ 0.249018] ** ** [ 0.251018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.254021] ************************************************************* [ 0.257941] NET: Registered protocol family 16 [ 0.259494] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.262082] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.265091] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.270038] cpuidle: using governor menu [ 0.272221] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.273735] PCI: Using configuration type 1 for base access [ 0.275160] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.284145] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.287076] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.292172] cryptd: max_cpu_qlen set to 1000 [ 0.293349] ACPI: Added _OSI(Module Device) [ 0.294014] ACPI: Added _OSI(Processor Device) [ 0.295069] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.297016] ACPI: Added _OSI(Processor Aggregator Device) [ 0.302295] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.309042] ACPI: Interpreter enabled [ 0.310050] ACPI: PM: (supports S0 S3 S4 S5) [ 0.311011] ACPI: Using IOAPIC for interrupt routing [ 0.313111] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.316863] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.326713] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.329037] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.332025] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.335078] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.339000] acpiphp: Slot [2] registered [ 0.339000] acpiphp: Slot [5] registered [ 0.339000] acpiphp: Slot [6] registered [ 0.340194] acpiphp: Slot [7] registered [ 0.341000] acpiphp: Slot [8] registered [ 0.342128] acpiphp: Slot [9] registered [ 0.344116] acpiphp: Slot [10] registered [ 0.345136] acpiphp: Slot [3] registered [ 0.347108] acpiphp: Slot [4] registered [ 0.348120] acpiphp: Slot [11] registered [ 0.350107] acpiphp: Slot [12] registered [ 0.351094] acpiphp: Slot [13] registered [ 0.353110] acpiphp: Slot [14] registered [ 0.354206] acpiphp: Slot [15] registered [ 0.356142] acpiphp: Slot [16] registered [ 0.358151] acpiphp: Slot [17] registered [ 0.360220] acpiphp: Slot [18] registered [ 0.362159] acpiphp: Slot [19] registered [ 0.364158] acpiphp: Slot [20] registered [ 0.367083] acpiphp: Slot [21] registered [ 0.368149] acpiphp: Slot [22] registered [ 0.370142] acpiphp: Slot [23] registered [ 0.371148] acpiphp: Slot [24] registered [ 0.373140] acpiphp: Slot [25] registered [ 0.375147] acpiphp: Slot [26] registered [ 0.377248] acpiphp: Slot [27] registered [ 0.378218] acpiphp: Slot [28] registered [ 0.380139] acpiphp: Slot [29] registered [ 0.382155] acpiphp: Slot [30] registered [ 0.384193] acpiphp: Slot [31] registered [ 0.386058] PCI host bridge to bus 0000:00 [ 0.387027] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.390024] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.393025] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.395021] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.398025] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.401088] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.402167] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.405132] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.408352] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.418794] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.422966] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.426073] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.428026] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.430018] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.433416] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.437987] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.441058] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.444075] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.449020] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.466023] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.472021] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.478476] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.489019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.499018] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.523018] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.532448] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.538027] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.546020] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.570022] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.580349] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.588613] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.596022] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.617023] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.629450] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.638018] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.650022] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.677022] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.692787] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.700017] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.710023] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.732021] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.741365] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.750019] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.755019] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.775022] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.789274] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.792662] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.795737] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.799501] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.801297] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.806687] iommu: Default domain type: Passthrough [ 0.808590] SCSI subsystem initialized [ 0.810199] ACPI: bus type USB registered [ 0.812150] usbcore: registered new interface driver usbfs [ 0.814086] usbcore: registered new interface driver hub [ 0.816159] usbcore: registered new device driver usb [ 0.818221] pps_core: LinuxPPS API ver. 1 registered [ 0.820014] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.823076] PTP clock support registered [ 0.826236] EDAC MC: Ver: 3.0.0 [ 0.828179] PCI: Using ACPI for IRQ routing [ 0.830009] NetLabel: Initializing [ 0.831012] NetLabel: domain hash size = 128 [ 0.832026] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.833115] NetLabel: unlabeled traffic allowed by default [ 0.834346] vgaarb: loaded [ 0.836351] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.837015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.841322] clocksource: Switched to clocksource kvm-clock [ 0.957055] VFS: Disk quotas dquot_6.6.0 [ 0.959335] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.962308] *** VALIDATE ramfs *** [ 0.963812] *** VALIDATE hugetlbfs *** [ 0.965968] pnp: PnP ACPI init [ 0.968523] pnp: PnP ACPI: found 6 devices [ 0.986611] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.991598] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.993834] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.996245] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.998739] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.001072] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.004059] NET: Registered protocol family 2 [ 1.006553] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.011299] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.016227] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.022333] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.026936] TCP: Hash tables configured (established 65536 bind 65536) [ 1.029581] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.033404] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.036362] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.039569] NET: Registered protocol family 1 [ 1.042933] RPC: Registered named UNIX socket transport module. [ 1.045696] RPC: Registered udp transport module. [ 1.047509] RPC: Registered tcp transport module. [ 1.049160] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.051712] NET: Registered protocol family 44 [ 1.053893] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.056638] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.059148] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.061558] PCI: CLS 0 bytes, default 64 [ 1.064298] Unpacking initramfs... [ 2.599337] debug: unmapping init [mem 0xffff88c63cc54000-0xffff88c63ffbffff] [ 2.603728] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.606520] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.609083] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.124068] Initialise system trusted keyrings [ 3.126080] Key type blacklist registered [ 3.128302] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.140631] zbud: loaded [ 3.144190] *** VALIDATE nfs *** [ 3.145289] *** VALIDATE nfs4 *** [ 3.146681] pstore: using deflate compression [ 3.149610] Platform Keyring initialized [ 3.282303] NET: Registered protocol family 38 [ 3.284401] Key type asymmetric registered [ 3.286339] Asymmetric key parser 'x509' registered [ 3.288604] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.291966] io scheduler mq-deadline registered [ 3.293653] io scheduler kyber registered [ 3.295541] io scheduler bfq registered [ 3.297856] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.301045] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.305361] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.309436] ACPI: Power Button [PWRF] [ 3.315790] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.323291] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.340560] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.349573] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.377992] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.408196] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.440790] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.445683] Non-volatile memory driver v1.3 [ 3.447327] Linux agpgart interface v0.103 [ 3.478828] virtio_blk virtio1: [vda] 149952 512-byte logical blocks (76.8 MB/73.2 MiB) [ 3.485163] vda: detected capacity change from 0 to 76775424 [ 3.501499] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.504629] vdb: detected capacity change from 0 to 1073741824 [ 3.522439] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.526400] vdc: detected capacity change from 0 to 2621440000 [ 3.543169] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.546320] vdd: detected capacity change from 0 to 2621440000 [ 3.565447] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.567427] vde: detected capacity change from 0 to 4294967296 [ 3.591681] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.595182] vdf: detected capacity change from 0 to 4294967296 [ 3.608334] libphy: Fixed MDIO Bus: probed [ 3.613520] usbcore: registered new interface driver usbserial_generic [ 3.615830] usbserial: USB Serial support registered for generic [ 3.618285] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.623101] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.624808] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.627182] mousedev: PS/2 mouse device common for all mice [ 3.629813] rtc_cmos 00:05: RTC can wake from S4 [ 3.634054] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.634619] rtc_cmos 00:05: registered as rtc0 [ 3.639972] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.641225] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.647429] intel_pstate: CPU model not supported [ 3.647806] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.652619] hid: raw HID events driver (C) Jiri Kosina [ 3.655376] usbcore: registered new interface driver usbhid [ 3.657604] usbhid: USB HID core driver [ 3.659468] drop_monitor: Initializing network drop monitor service [ 3.662047] Initializing XFRM netlink socket [ 3.664182] NET: Registered protocol family 10 [ 3.668280] Segment Routing with IPv6 [ 3.670035] NET: Registered protocol family 17 [ 3.672747] mpls_gso: MPLS GSO support [ 3.678575] RAS: Correctable Errors collector initialized. [ 3.680653] AVX version of gcm_enc/dec engaged. [ 3.682142] AES CTR mode by8 optimization enabled [ 3.763618] sched_clock: Marking stable (3763478160, 0)->(4685031360, -921553200) [ 3.767719] registered taskstats version 1 [ 3.769507] Loading compiled-in X.509 certificates [ 3.771639] zswap: loaded using pool lzo/zbud [ 3.798834] Key type big_key registered [ 3.813579] Key type encrypted registered [ 3.815257] ima: No TPM chip found, activating TPM-bypass! [ 3.820483] ima: Allocated hash algorithm: sha1 [ 3.822710] ima: No architecture policies found [ 3.824372] evm: Initialising EVM extended attributes: [ 3.826357] evm: security.selinux [ 3.827527] evm: security.ima [ 3.828637] evm: security.capability [ 3.829740] evm: HMAC attrs: 0x1 [ 3.832172] rtc_cmos 00:05: setting system clock to 2026-09-10 17:16:43 UTC (1789060603) [ 3.839459] debug: unmapping init [mem 0xffffffffa1803000-0xffffffffa19fffff] [ 3.843270] debug: unmapping init [mem 0xffffffffa0582000-0xffffffffa0858fff] [ 3.853090] Write protecting the kernel read-only data: 28672k [ 3.857673] debug: unmapping init [mem 0xffffffff9ec03000-0xffffffff9edfffff] [ 3.860962] debug: unmapping init [mem 0xffffffff9f514000-0xffffffff9f5fffff] [ 3.908198] 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.919202] systemd[1]: Detected virtualization kvm. [ 3.921337] systemd[1]: Detected architecture x86-64. [ 3.923921] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.954611] systemd[1]: No hostname configured. [ 3.956657] systemd[1]: Set hostname to . [ 3.958931] random: systemd: uninitialized urandom read (16 bytes read) [ 3.961789] systemd[1]: Initializing machine ID from random generator. [ 4.105826] random: systemd: uninitialized urandom read (16 bytes read) [ 4.108730] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 4.114152] random: systemd: uninitialized urandom read (16 bytes read) [ 4.117600] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 4.127454] systemd[1]: Started Memstrack Anylazing Service. [ OK ] Started Memstrack Anylazing Service. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Timers. Starting Create list of required st…ce nodes for the current kernel... Starting Create Volatile Files and Directories... [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Swap. Starting Setup Virtual Console... [ OK ] Reached target Slices. Starting Apply Kernel Variables... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. 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.798182] device-mapper: uevent: version 1.0.3 [ 4.800784] 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...[ 5.404166] random: fast init done [ 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.619056] virtio_net virtio0 ens2: renamed from eth0 [ 5.708667] scsi host0: ata_piix [ 5.721460] scsi host1: ata_piix [ 5.723195] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.726190] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.524732] dracut-initqueue[579]: RTNETLINK answers: File exists [ 10.335455] random: crng init done [ 10.336852] 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.857748] 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 Initrd Default Target. [ OK ] Stopped target Timers. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 12.011995] printk: systemd: 25 output lines suppressed due to ratelimiting [ 12.266240] SELinux: Disabled at runtime. [ 12.327879] 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.336428] systemd[1]: Detected virtualization kvm. [ 12.338469] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.847674] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.852680] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.858561] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.862742] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.866574] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.874398] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.891403] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on RPCbind Server Activation Socket. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice User and Session Slice. Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting Kernel Debug File System... [ OK ] Stopped target Switch Root. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Listening on initctl Compatibility Named Pipe. Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target RPC Port Mapper. Mounting Huge Pages File System... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting POSIX M[ 13.002663] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS essage Queue File System... [ OK ] Stopped target Initrd Root File System. [ OK ] Reached target Slices. [ OK ] Stopped target Initrd File Systems. [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-getty.slice. Starting Apply Kernel Variables... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ 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. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.309511] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.609739] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.622380] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.767759] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.782989] EDAC sbridge: Ver: 1.1.2 [ 15.375594] Key type dns_resolver registered [ 15.673208] NFS: Registering the id_resolver key type [ 15.674559] Key type id_resolver registered [ 15.675662] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ 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 ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting 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 oleg624-server login: [ 52.056989] hrtimer: interrupt took 9066071 ns [ 58.720184] libcfs: loading out-of-tree module taints kernel. [ 58.744327] Key type ._llcrypt registered [ 58.747041] Key type .llcrypt registered [ 58.856653] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_hostid [ 81.144468] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 82.583699] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 82.596709] alg: No test for adler32 (adler32-zlib) [ 84.220557] Lustre: Lustre: Build Version: 2.17.58_39_ga794951 [ 85.296671] LNet: Added LNI 192.168.206.124@tcp [8/256/0/180] [ 87.185894] Key type lgssc registered [ 89.087041] Lustre: Echo OBD driver; http://www.lustre.org/ [ 104.117512] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 143.818432] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 156.848904] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 156.889304] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 158.152174] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 158.189978] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 158.273859] Lustre: lustre-MDT0000: new disk, initializing [ 158.354945] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 158.390792] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 162.666728] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 175.582769] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 175.713555] Lustre: 6508:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 175.766461] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 175.772352] Lustre: Skipped 1 previous similar message [ 175.849595] Lustre: lustre-MDT0001: new disk, initializing [ 175.891922] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 175.919993] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 175.928785] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 179.755976] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 184.363756] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 193.824793] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 193.982747] Lustre: lustre-OST0000: new disk, initializing [ 193.985841] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 193.990849] Lustre: 8447:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 194.049990] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 199.823793] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 201.737834] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 201.744202] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 201.811216] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 213.161959] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 213.273408] Lustre: lustre-OST0001: new disk, initializing [ 213.276137] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 213.279916] Lustre: 9519:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 213.336336] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 219.418782] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 220.214587] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 220.230360] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 220.292221] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 230.310501] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 240.315380] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 246.418186] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing check_logdir /tmp/testlogs/ [ 251.003497] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing yml_node [ 255.657532] Lustre: DEBUG MARKER: Client: 2.17.58.39 [ 257.807420] Lustre: DEBUG MARKER: MDS: 2.17.58.39 [ 260.277931] Lustre: DEBUG MARKER: OSS: 2.17.58.39 [ 261.716720] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Thu Sep 10 13:20:59 EDT 2026 [ 277.224788] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 279.007640] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 [ 282.245151] Lustre: DEBUG MARKER: === sanity-quota: start setup 13:21:19 (1789060879) === [ 287.901203] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing check_config_client /mnt/lustre [ 305.894689] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 308.977353] Lustre: 13424:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 312.640883] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 318.692721] Lustre: DEBUG MARKER: === sanity-quota: finish setup 13:21:55 (1789060915) === [ 379.949465] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 13:22:57 (1789060977) [ 423.896536] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 13:23:41 (1789061021) [ 434.766382] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 442.782984] Lustre: DEBUG MARKER: Write... [ 445.067350] Lustre: DEBUG MARKER: Write out of block quota ... [ 479.437961] Lustre: DEBUG MARKER: -------------------------------------- [ 481.277898] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 489.247921] Lustre: DEBUG MARKER: Write... [ 492.015561] Lustre: DEBUG MARKER: Write out of block quota ... [ 532.867648] Lustre: DEBUG MARKER: -------------------------------------- [ 534.509635] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 537.483890] Lustre: DEBUG MARKER: Write... [ 540.516526] Lustre: DEBUG MARKER: Write out of block quota ... [ 588.844612] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 13:26:26 (1789061186) [ 601.870243] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 623.055969] Lustre: DEBUG MARKER: Write... [ 625.820485] Lustre: DEBUG MARKER: Write out of block quota ... [ 658.348077] Lustre: DEBUG MARKER: -------------------------------------- [ 660.018411] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 666.495412] Lustre: DEBUG MARKER: Write... [ 668.903161] Lustre: DEBUG MARKER: Write out of block quota ... [ 706.447407] Lustre: DEBUG MARKER: -------------------------------------- [ 708.248446] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 711.480064] Lustre: DEBUG MARKER: Write... [ 714.018402] Lustre: DEBUG MARKER: Write out of block quota ... [ 776.570616] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 13:29:34 (1789061374) [ 789.163207] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 819.876922] Lustre: DEBUG MARKER: Write... [ 823.042534] Lustre: DEBUG MARKER: Write out of block quota ... [ 909.374310] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 13:31:47 (1789061507) [ 920.154244] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 946.550930] Lustre: DEBUG MARKER: Write... [ 949.025720] Lustre: DEBUG MARKER: Write out of block quota ... [ 1033.570493] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 13:33:51 (1789061631) [ 1044.833348] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 1058.869839] Lustre: DEBUG MARKER: Write... [ 1061.288984] Lustre: DEBUG MARKER: Write out of block quota ... [ 1074.114772] Lustre: DEBUG MARKER: Write... [ 1127.369855] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 13:35:24 (1789061724) [ 1139.325778] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1153.473882] Lustre: DEBUG MARKER: Write... [ 1155.831397] Lustre: DEBUG MARKER: Write out of block quota ... [ 1186.275972] Lustre: DEBUG MARKER: Write... [ 1188.805891] Lustre: DEBUG MARKER: Write out of block quota ... [ 1234.833322] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 13:37:12 (1789061832) [ 1246.128870] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 1259.509232] Lustre: 6516:0:(osd_handler.c:2191:osd_trans_start()) lustre-MDT0000: credits 6570 > trans_max 3200 [ 1259.518051] Lustre: 6516:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 4/16/0, destroy: 0/0/0 [ 1259.530664] Lustre: 6516:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 401/401/0, xattr_set: 602/5615/0 [ 1259.539890] Lustre: 6516:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 20/142/0, punch: 0/0/0, quota 8/328/0 [ 1259.547320] Lustre: 6516:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/68/0, delete: 0/0/0 [ 1259.556407] Lustre: 6516:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1259.561943] CPU: 0 PID: 6516 Comm: mdt00_001 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [ 1259.567629] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 1259.572432] Call Trace: [ 1259.573604] ? dump_stack+0xbb/0x10e [ 1259.575393] ? osd_trans_start+0x8db/0x9d0 [osd_ldiskfs] [ 1259.577981] ? dt_trans_start+0x1c/0x70 [obdclass] [ 1259.579788] ? top_trans_start+0x4fd/0xd00 [ptlrpc] [ 1259.582434] ? lod_xattr_list+0x30/0x30 [lod] [ 1259.584458] ? lod_trans_start+0x109/0x4c0 [lod] [ 1259.586628] ? mdd_declare_attr_set+0x91/0x880 [mdd] [ 1259.590497] ? mdd_env_info+0x25/0xc0 [mdd] [ 1259.593382] ? mdd_trans_start+0x18/0x30 [mdd] [ 1259.596234] ? mdd_attr_set+0xa5a/0x1330 [mdd] [ 1259.598210] ? mdt_reint_setattr+0x14aa/0x2030 [mdt] [ 1259.600665] ? mdt_reint_setattr+0x14aa/0x2030 [mdt] [ 1259.603023] ? mdt_reint_rec+0x139/0x2b0 [mdt] [ 1259.605170] ? mdt_reint_internal+0x693/0xdc0 [mdt] [ 1259.609367] ? mdt_reint+0x163/0x190 [mdt] [ 1259.611380] ? tgt_handle_request0+0x137/0xaf0 [ptlrpc] [ 1259.613517] ? tgt_request_handle+0x575/0x1f70 [ptlrpc] [ 1259.616505] ? ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [ 1259.619495] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [ 1259.622461] ? ptlrpc_main+0xce8/0x1400 [ptlrpc] [ 1259.624788] ? ptlrpc_wait_event+0x690/0x690 [ptlrpc] [ 1259.627428] ? kthread+0x1d1/0x200 [ 1259.629026] ? set_kthread_struct+0x70/0x70 [ 1259.630877] ? ret_from_fork+0x1f/0x30 [ 1261.488361] Lustre: DEBUG MARKER: Write... [ 1272.700816] Lustre: DEBUG MARKER: Write out of block quota ... [ 1341.905255] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 13:38:59 (1789061939) [ 1353.305102] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 1359.548907] Lustre: DEBUG MARKER: Write 5MiB Using Fallocate [ 1366.934226] Lustre: DEBUG MARKER: Write 11MiB Using Fallocate [ 1449.095739] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 13:40:46 (1789062046) [ 1465.340616] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 1479.135410] Lustre: DEBUG MARKER: Write... [ 1482.420525] Lustre: DEBUG MARKER: Write out of block quota ... [ 1511.193907] Lustre: DEBUG MARKER: Write... [ 1513.692920] Lustre: DEBUG MARKER: Write out of block quota ... [ 1525.460340] LustreError: 6517:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:14344 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 1568.755744] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 13:42:45 (1789062165) [ 1587.795994] Lustre: DEBUG MARKER: -------------------------------------- [ 1589.382110] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 1964.475693] Lustre: DEBUG MARKER: == sanity-quota test 1k: LQA: Block hard limit (normal use and out of quota) ========================================================== 13:49:22 (1789062562) [ 1979.127681] Lustre: DEBUG MARKER: Write... [ 1982.376459] Lustre: DEBUG MARKER: Write out of block quota ... [ 2011.635876] Lustre: DEBUG MARKER: Write... [ 2014.507094] Lustre: DEBUG MARKER: Write out of block quota ... [ 2045.611198] Lustre: DEBUG MARKER: Write... [ 2050.203468] Lustre: DEBUG MARKER: Write out of block quota ... [ 2089.228769] Lustre: DEBUG MARKER: == sanity-quota test 1l: Async writes should not be rejected by quota with root_prj_enable ========================================================== 13:51:26 (1789062686) [ 2132.509364] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 2134.324183] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 13:52:11 (1789062731) [ 2181.620404] Lustre: DEBUG MARKER: Write after timer goes off [ 2184.551393] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2261.399059] Lustre: DEBUG MARKER: Write after timer goes off [ 2264.440094] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2331.857760] Lustre: DEBUG MARKER: Write after timer goes off [ 2335.107374] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2414.068889] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 13:56:51 (1789063011) [ 2473.393464] Lustre: DEBUG MARKER: Write after timer goes off [ 2475.596808] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2549.263854] Lustre: DEBUG MARKER: Write after timer goes off [ 2551.348698] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2626.446575] Lustre: DEBUG MARKER: Write after timer goes off [ 2628.843783] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2714.503075] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 14:01:52 (1789063312) [ 2779.363516] Lustre: DEBUG MARKER: Write after timer goes off [ 2782.964842] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2862.612524] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 2864.474435] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 14:04:21 (1789063461) [ 2874.884698] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 3008.524122] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 14:06:45 (1789063605) [ 3047.393720] Lustre: *** cfs_fail_loc=513, val=601*** [ 3048.417425] Lustre: *** cfs_fail_loc=513, val=601*** [ 3049.426663] Lustre: *** cfs_fail_loc=513, val=601*** [ 3049.431787] Lustre: Skipped 16 previous similar messages [ 3049.526148] LustreError: 16534:0:(service.c:2346:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1875966098869504 [ 3051.489759] Lustre: *** cfs_fail_loc=513, val=601*** [ 3051.498292] Lustre: Skipped 10 previous similar messages [ 3056.620830] Lustre: *** cfs_fail_loc=513, val=601*** [ 3056.636827] Lustre: Skipped 18 previous similar messages [ 3064.802070] Lustre: 42253:0:(service.c:1612:ptlrpc_at_send_early_reply()) @@@ Could not add any time (5/5), not sending early reply req@ffff88c58aae3480 x1875966080949248/t0(0) o4->c18e2b19-48ee-429d-bc28-40ede8c45e39@192.168.206.24@tcp:569/0 lens 488/448 e 1 to 0 dl 1789063669 ref 2 fl Interpret:/600/0 rc 0/0 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 3065.824185] Lustre: 8437:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063649/real 1789063649] req@ffff88c6bfb64e00 x1875966098869504/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1789063665 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_001.0' uid:0 gid:0 projid:4294967295 [ 3065.851088] 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 [ 3065.887551] Lustre: *** cfs_fail_loc=513, val=601*** [ 3065.889110] Lustre: Skipped 33 previous similar messages [ 3065.904058] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3065.919885] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3066.005464] LustreError: 6518:0:(service.c:2346:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1875966098878592 [ 3068.896824] LustreError: 6519:0:(service.c:2346:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1875966098879104 [ 3068.906961] LustreError: 6519:0:(service.c:2346:ptlrpc_server_handle_req_in()) Skipped 2 previous similar messages [ 3082.209238] Lustre: *** cfs_fail_loc=513, val=601*** [ 3082.212814] Lustre: 42400:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063665/real 1789063665] req@ffff88c588700000 x1875966098878592/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1789063681 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_006.0' uid:0 gid:0 projid:4294967295 [ 3082.213433] Lustre: Skipped 79 previous similar messages [ 3082.249177] 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 [ 3082.262986] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3082.290044] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3083.959910] LustreError: 6518:0:(service.c:2346:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1875966098888448 [ 3084.368528] Lustre: 3641:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063668/real 1789063668] req@ffff88c58dfd8700 x1875966098879232/t0(0) o601->lustre-MDT0000-lwp-MDT0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1789063684 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [ 3084.415581] 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 [ 3084.435968] Lustre: lustre-MDT0000: Received new LWP connection from 0@lo, keep former export from same NID [ 3084.461088] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3089.376784] LustreError: 6519:0:(service.c:2346:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1875966098890880 [ 3089.396298] LustreError: 6519:0:(service.c:2346:ptlrpc_server_handle_req_in()) Skipped 5 previous similar messages [ 3100.130732] Lustre: 18284:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063683/real 1789063683] req@ffff88c58766e300 x1875966098888448/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1789063699 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 3100.153254] Lustre: 18284:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 3100.162710] 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 [ 3100.184540] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 3100.196413] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3106.272130] Lustre: 3644:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063689/real 1789063689] req@ffff88c6bfc55c00 x1875966098890752/t0(0) o601->lustre-MDT0000-lwp-OST0001@0@lo:23/10 lens 336/336 e 0 to 1 dl 1789063705 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'lquota_wb_lustr.0' uid:0 gid:0 projid:4294967295 [ 3106.273246] 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 [ 3106.294891] Lustre: 3644:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 3106.330753] Lustre: Skipped 1 previous similar message [ 3106.366718] Lustre: lustre-MDT0000: Received new LWP connection from 0@lo, keep former export from same NID [ 3106.366759] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0001_UUID (at 0@lo) reconnecting [ 3106.377162] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3134.516507] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 14:08:51 (1789063731) [ 3162.707328] Lustre: Failing over lustre-OST0000 [ 3163.065789] Lustre: server umount lustre-OST0000 complete [ 3166.166477] LustreError: lustre-OST0000-osc-MDT0000: operation ost_setattr to node 0@lo failed: rc = -107 [ 3166.179578] 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 [ 3166.185027] LustreError: Skipped 1 previous similar message [ 3169.945741] LustreError: 42138:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3169.975552] LustreError: 42138:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 6 previous similar messages [ 3172.839360] LustreError: 42489:0:(ldlm_lib.c:1199: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. [ 3172.865459] LustreError: 42489:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 3175.063190] LustreError: 8910:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3176.690880] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3177.002270] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3177.039988] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3178.097746] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3179.029252] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3179.029733] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3179.034974] Lustre: Skipped 1 previous similar message [ 3183.695100] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3192.152222] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3198.552615] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3204.358959] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3210.207928] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3215.380503] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3220.894930] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3243.725971] Lustre: Failing over lustre-OST0000 [ 3243.884287] Lustre: server umount lustre-OST0000 complete [ 3245.537500] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 3245.544289] 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 [ 3245.544554] LustreError: Skipped 2 previous similar messages [ 3245.552872] Lustre: Skipped 1 previous similar message [ 3245.564241] LustreError: 42487:0:(ldlm_lib.c:1199: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. [ 3245.583924] LustreError: 42487:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 3251.811654] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3252.114859] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3252.151648] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3253.541161] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3260.262967] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3270.988902] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3323.502765] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 3323.507355] Lustre: 87543:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client c18e2b19-48ee-429d-bc28-40ede8c45e39@ [ 3323.522755] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 3323.569618] Lustre: lustre-OST0000: Recovery over after 1:10, of 3 clients 2 recovered and 1 was evicted. [ 3323.571052] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3323.590045] Lustre: Skipped 1 previous similar message [ 3332.197202] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3337.024290] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3342.015217] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3346.770344] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3351.885941] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3379.571479] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 14:12:57 (1789063977) [ 3411.921145] Lustre: *** cfs_fail_loc=a02, val=0*** [ 3418.739508] Lustre: Failing over lustre-OST0000 [ 3418.830398] Lustre: server umount lustre-OST0000 complete [ 3420.880237] LustreError: 8433:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3420.898036] LustreError: 8433:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [ 3421.153551] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 3421.157427] 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 [ 3421.163424] LustreError: Skipped 1 previous similar message [ 3421.182395] Lustre: Skipped 1 previous similar message [ 3427.106925] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3427.421566] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3427.453721] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3428.585749] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3429.226118] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3429.226918] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3429.246676] Lustre: Skipped 1 previous similar message [ 3432.806673] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3440.528758] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3446.272917] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3452.548778] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3457.680926] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3462.695993] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3468.054741] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3504.634948] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 14:15:02 (1789064102) [ 3526.712750] LustreError: 97303:0:(qsd_reint.c:488:qsd_reint_main()) cfs_fail_timeout id a03 sleeping for 10000ms [ 3526.726360] LustreError: 97303:0:(qsd_reint.c:488:qsd_reint_main()) Skipped 5 previous similar messages [ 3528.477202] Lustre: Failing over lustre-MDT0000 [ 3528.733213] Lustre: server umount lustre-MDT0000 complete [ 3529.702218] 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 [ 3529.717052] LustreError: 6520:0:(ldlm_lib.c:1199: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. [ 3529.717146] Lustre: Skipped 2 previous similar messages [ 3529.751792] LustreError: 6520:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 8 previous similar messages [ 3531.984099] LustreError: 97308:0:(qsd_reint.c:488:qsd_reint_main()) cfs_fail_timeout interrupted [ 3539.371750] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3539.508758] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3539.750402] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3539.827148] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3543.716380] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3544.025136] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3545.065915] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3545.077812] Lustre: Skipped 1 previous similar message [ 3545.092407] LustreError: 3640:0:(ldlm_resource.c:1207:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x2020000:0x0].0x0 (ffff88c685ebba00) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 3545.219489] Lustre: 97308:0:(qsd_reint.c:249:qsd_reint_index()) lustre-OST0001: index version for fid [0x200000005:0x100c:0x0] is 0, but index isn't empty (1) [ 3545.242828] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 3545.308697] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:143 to 0x280000401:161) [ 3545.311200] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:121 to 0x2c0000401:161) [ 3550.936820] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3647.584644] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3651.629102] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3655.594486] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3660.375582] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3665.491784] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3694.394522] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 14:18:11 (1789064291) [ 3714.348051] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 3719.217421] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 3755.478839] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 14:19:12 (1789064352) [ 3778.891244] Lustre: Failing over lustre-MDT0001 [ 3779.239313] LustreError: 6515:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3779.249195] LustreError: 6515:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 6 previous similar messages [ 3779.290312] Lustre: server umount lustre-MDT0001 complete [ 3780.580259] 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 [ 3780.592147] Lustre: Skipped 3 previous similar messages [ 3780.596289] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3792.517993] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3792.892989] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3792.946541] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3794.598732] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3796.490097] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3797.989703] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3798.004286] Lustre: Skipped 3 previous similar messages [ 3798.032065] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 3798.089654] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:33) [ 3803.903166] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3808.846571] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3814.020916] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3819.506189] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3824.202133] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3829.085353] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3907.069982] Lustre: Failing over lustre-MDT0001 [ 3907.268346] LustreError: 6516:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3907.288712] LustreError: 6516:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 11 previous similar messages [ 3907.366848] Lustre: server umount lustre-MDT0001 complete [ 3910.632260] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3915.190855] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3915.829432] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3915.900339] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3917.323108] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3920.475189] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3920.882908] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 3920.914102] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:65) [ 3928.257221] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3933.911518] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3939.837199] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3945.560325] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3950.963288] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 3956.603710] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4046.718585] Lustre: DEBUG MARKER: == sanity-quota test 7f: Quota reintegration automatically ========================================================== 14:24:03 (1789064643) [ 4061.409119] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4067.810041] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4121.575146] Lustre: *** cfs_fail_loc=a11, val=0*** [ 4121.591215] Lustre: Skipped 1 previous similar message [ 4121.640294] Lustre: 113979:0:(qsd_reint.c:249:qsd_reint_index()) lustre-MDT0001: index version for fid [0x200000005:0x1004:0x0] is 0, but index isn't empty (1) [ 4165.631880] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 14:26:03 (1789064763) [ 4356.517835] Lustre: DEBUG MARKER: == sanity-quota test 9: Block limit larger than 4GB (b10707) ========================================================== 14:29:14 (1789064954) [ 4358.299081] Lustre: DEBUG MARKER: OST0_SIZE: 3605072 required: 4900000 [ 4365.123892] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 14:29:22 (1789064962) [ 4407.790332] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 14:30:05 (1789065005) [ 4448.621103] Lustre: DEBUG MARKER: == sanity-quota test 12a: Block quota rebalancing ======== 14:30:46 (1789065046) [ 4519.306244] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 14:31:56 (1789065116) [ 4661.986308] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 14:34:19 (1789065259) [ 4722.171329] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 14:35:19 (1789065319) [ 4744.829692] Lustre: Failing over lustre-OST0000 [ 4745.024156] Lustre: server umount lustre-OST0000 complete [ 4745.188028] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 4745.196834] 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 [ 4745.212305] Lustre: Skipped 4 previous similar messages [ 4745.221457] LustreError: 115577:0:(ldlm_lib.c:1199: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. [ 4745.240206] LustreError: 115577:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 4 previous similar messages [ 4755.428441] LustreError: 8433:0:(ldlm_lib.c:1199: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. [ 4755.445610] LustreError: 8433:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [ 4757.621442] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4757.883239] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4757.911463] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4759.271531] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 4759.865733] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 4759.868571] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4759.892171] Lustre: Skipped 5 previous similar messages [ 4762.749410] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4801.820311] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 14:36:38 (1789065398) [ 4825.149987] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 14:37:02 (1789065422) [ 4842.122714] Lustre: lustre-MDT0001: Client c18e2b19-48ee-429d-bc28-40ede8c45e39 (at 192.168.206.24@tcp) reconnecting [ 4864.585357] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 14:37:42 (1789065462) [ 4865.854293] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 4867.419190] Lustre: DEBUG MARKER: == sanity-quota test 16c: lfs quota should preserve usage with an unavailable OST ========================================================== 14:37:45 (1789065465) [ 4880.569086] Lustre: setting import lustre-OST0000_UUID INACTIVE by administrator request [ 4881.393233] Lustre: setting import lustre-OST0000_UUID INACTIVE by administrator request [ 4882.867404] Lustre: Failing over lustre-OST0000 [ 4882.955675] Lustre: server umount lustre-OST0000 complete [ 4883.142808] LustreError: 115595:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4883.157433] LustreError: 115595:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 4891.747037] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state (DISCONN|IDLE) osc.lustre-OST0000-osc-ffff8a50987e9800.ost_server_uuid 50 [ 4892.918086] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8a50987e9800.ost_server_uuid in DISCONN state after 0 sec [ 4899.266981] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4899.502271] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 4899.526744] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4900.655923] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 4900.662392] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 4902.550595] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:57 [ 4904.436200] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4906.735900] 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 [ 4906.747544] Lustre: Skipped 1 previous similar message [ 4906.751633] LustreError: lustre-OST0000-osc-MDT0000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 4906.765723] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4906.768406] Lustre: Skipped 1 previous similar message [ 4906.768923] LustreError: 20844:0:(tgt_handler.c:534:tgt_filter_recovery_request()) @@@ not permitted during recovery req@ffff88c6b765a300 x1875966101263488/t0(0) o7->lustre-MDT0000-mdtlov_UUID@0@lo:152/0 lens 264/0 e 0 to 0 dl 1789065517 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-pre-0-0.0' uid:0 gid:0 projid:4294967295 [ 4906.777184] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -11 [ 4906.803628] LustreError: 20844:0:(tgt_handler.c:534:tgt_filter_recovery_request()) Skipped 1 previous similar message [ 4906.813716] LustreError: Skipped 1 previous similar message [ 4907.435521] LustreError: lustre-OST0000-osc-MDT0001: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 4907.448029] LustreError: 42487:0:(tgt_handler.c:534:tgt_filter_recovery_request()) @@@ not permitted during recovery req@ffff88c589d9c380 x1875966101263872/t0(0) o7->lustre-MDT0001-mdtlov_UUID@0@lo:153/0 lens 264/0 e 0 to 0 dl 1789065518 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-pre-0-1.0' uid:0 gid:0 projid:4294967295 [ 4907.466368] LustreError: 42487:0:(tgt_handler.c:534:tgt_filter_recovery_request()) Skipped 1 previous similar message [ 4907.670076] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 2 in progress, and 0 evicted) to recover in 1:02 [ 4910.711936] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 4912.794688] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 2 in progress, and 0 evicted) to recover in 0:57 [ 4917.910180] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 2 in progress, and 0 evicted) to recover in 0:52 [ 4928.154691] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 2 in progress, and 0 evicted) to recover in 0:42 [ 4928.168701] Lustre: Skipped 1 previous similar message [ 4948.639748] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 2 in progress, and 0 evicted) to recover in 0:21 [ 4948.654497] Lustre: Skipped 3 previous similar messages [ 4970.505265] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 4970.511447] Lustre: 131243:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client c18e2b19-48ee-429d-bc28-40ede8c45e39@ [ 4970.518479] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 4984.470099] Lustre: lustre-OST0000: Denying connection for new client 4242e2ac-5f5d-4ef3-baeb-b165bebdc9e2 (at 192.168.206.24@tcp), waiting for 3 known clients (0 recovered, 2 in progress, and 1 evicted) to recover in 0:16 [ 4984.485113] Lustre: Skipped 6 previous similar messages [ 5000.500453] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 5000.505301] Lustre: 131243:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client lustre-MDT0000-mdtlov_UUID@0@lo [ 5000.512858] Lustre: lustre-OST0000: disconnecting 2 stale clients [ 5000.530875] Lustre: lustre-OST0000: Recovery over after 1:40, of 3 clients 0 recovered and 3 were evicted. [ 5002.217633] 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 [ 5002.228874] Lustre: Skipped 1 previous similar message [ 5002.241413] LustreError: lustre-OST0000-osc-MDT0000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 5002.258117] LustreError: lustre-OST0000-osc-MDT0001: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 5002.258873] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 5002.291900] Lustre: Skipped 2 previous similar messages [ 5005.972381] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 5006.212899] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 5010.430369] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 5010.608851] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 5016.801481] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff8a50987e9800.ost_server_uuid 50 [ 5018.670232] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8a50987e9800.ost_server_uuid in FULL state after 0 sec [ 5043.358331] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 14:40:41 (1789065641) [ 5062.235621] Lustre: *** cfs_fail_loc=a04, val=37*** [ 5062.241345] LustreError: 115584:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0000 qtype:usr lqe: ffff88c6c1235200 id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 5063.341379] Lustre: *** cfs_fail_loc=a04, val=37*** [ 5063.346148] LustreError: 18284:0:(qsd_handler.c:298:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0000 qtype:usr lqe: ffff88c6c1235200 id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 [ 5113.721626] Lustre: *** cfs_fail_loc=a04, val=11*** [ 5116.848199] Lustre: *** cfs_fail_loc=a04, val=11*** [ 5116.850282] Lustre: Skipped 1 previous similar message [ 5170.872338] Lustre: *** cfs_fail_loc=a04, val=110*** [ 5226.261793] Lustre: *** cfs_fail_loc=a04, val=107*** [ 5226.263544] Lustre: Skipped 2 previous similar messages [ 5302.652940] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 14:45:00 (1789065900) [ 5314.083133] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5319.385123] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 5327.194567] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5328.456263] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5330.505478] Lustre: Failing over lustre-MDT0000 [ 5330.966645] Lustre: server umount lustre-MDT0000 complete [ 5332.641525] LustreError: 6515:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5332.657272] LustreError: 6515:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [ 5333.991233] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5333.998258] LustreError: Skipped 2 previous similar messages [ 5334.002593] 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 [ 5334.019494] Lustre: Skipped 1 previous similar message [ 5350.368229] Lustre: 3641:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789065934/real 1789065934] req@ffff88c6812aa680 x1875966101505664/t0(0) o400->MGC192.168.206.124@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789065950 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5350.400916] Lustre: 3641:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 5350.409428] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5353.463244] LDISKFS-fs (dm-0): 7 truncates cleaned up [ 5353.465835] LDISKFS-fs (dm-0): recovery complete [ 5353.476963] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5360.611891] LustreError: 3640:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff88c687015180 x1875966101513472/t0(0) o250->MGC192.168.206.124@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5360.817151] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5360.852608] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5361.725703] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5365.376634] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5366.248257] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5366.329388] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 5366.392266] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:671 to 0x2c0000401:705) [ 5366.392267] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:674 to 0x280000401:705) [ 5375.412940] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5377.009902] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5382.660814] Lustre: DEBUG MARKER: (dd_pid=129969, time=0, timeout=600) [ 5408.515625] Lustre: DEBUG MARKER: User quota (limit: 200) [ 5414.658769] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 5422.172657] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5423.674686] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 5425.464340] Lustre: Failing over lustre-MDT0000 [ 5425.821846] Lustre: server umount lustre-MDT0000 complete [ 5427.681319] LustreError: 129238:0:(ldlm_lib.c:1199: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. [ 5427.695192] LustreError: 129238:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 33 previous similar messages [ 5443.545864] Lustre: 3644:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789066027/real 1789066027] req@ffff88c58d1a2a00 x1875966101564288/t0(0) o400->MGC192.168.206.124@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789066043 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5443.571425] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5447.110805] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 5447.118155] LDISKFS-fs (dm-0): recovery complete [ 5447.128158] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5454.070831] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5454.130644] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5454.642550] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5458.742491] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5459.443891] LustreError: 3640:0:(ldlm_resource.c:1207:ldlm_resource_complain()) lustre-MDT0000-lwp-MDT0001: namespace resource [0x200000006:0x20000:0x0].0x0 (ffff88c68709c800) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 5459.474921] LustreError: 3640:0:(ldlm_resource.c:1207:ldlm_resource_complain()) Skipped 5 previous similar messages [ 5459.530577] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 5459.587670] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:707 to 0x280000401:737) [ 5459.588653] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:671 to 0x2c0000401:737) [ 5468.434761] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5469.980647] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5475.580483] Lustre: DEBUG MARKER: (dd_pid=132375, time=0, timeout=600) [ 5515.299569] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 14:48:32 (1789066112) [ 5568.797591] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 14:49:26 (1789066166) [ 5596.424102] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 5607.940521] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 5609.555778] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 5610.925806] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 5612.472958] Lustre: DEBUG MARKER: Set quota for 1 times [ 5615.233897] Lustre: DEBUG MARKER: Set quota for 2 times [ 5618.486665] Lustre: DEBUG MARKER: Set quota for 3 times [ 5621.846165] Lustre: DEBUG MARKER: Set quota for 4 times [ 5624.953831] Lustre: DEBUG MARKER: Set quota for 5 times [ 5628.198225] Lustre: DEBUG MARKER: Set quota for 6 times [ 5631.212405] Lustre: DEBUG MARKER: Set quota for 7 times [ 5634.600752] Lustre: DEBUG MARKER: Set quota for 8 times [ 5637.717564] Lustre: DEBUG MARKER: Set quota for 9 times [ 5640.676406] Lustre: DEBUG MARKER: Set quota for 10 times [ 5669.123345] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 14:51:06 (1789066266) [ 5684.714577] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5684.715942] 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 [ 5684.729084] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5684.754615] Lustre: Skipped 8 previous similar messages [ 5684.782772] Lustre: Skipped 3 previous similar messages [ 5687.330507] Lustre: server umount lustre-MDT0000 complete [ 5689.825638] LustreError: 6517:0:(ldlm_lib.c:1199: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. [ 5689.842598] LustreError: 6517:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 29 previous similar messages [ 5690.923424] LustreError: 6500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789066290 with bad export cookie 50129384280649417 [ 5690.932629] LustreError: 6500:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 5690.935297] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5691.251734] Lustre: server umount lustre-MDT0001 complete [ 5705.354333] Lustre: server umount lustre-OST0000 complete [ 5719.369516] Lustre: server umount lustre-OST0001 complete [ 5734.505849] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 5744.246505] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5745.004110] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5749.707348] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5758.009368] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5758.423521] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5762.675412] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5765.697327] Lustre: 157576:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5771.393619] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5771.764304] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5777.623970] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5783.028396] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:97) [ 5785.859312] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5786.164898] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5790.251108] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:739 to 0x2c0000401:769) [ 5790.262167] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:740 to 0x280000401:769) [ 5791.628388] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5798.104511] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5801.184832] Lustre: 159453:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5820.908083] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5820.919357] Lustre: Skipped 2 previous similar messages [ 5826.017667] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5826.026438] Lustre: Skipped 3 previous similar messages [ 5827.001553] Lustre: server umount lustre-MDT0000 complete [ 5830.599520] LustreError: 156406:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789066430 with bad export cookie 50129384280661926 [ 5830.604401] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5830.617601] LustreError: 156406:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 5831.037590] Lustre: server umount lustre-MDT0001 complete [ 5845.378680] Lustre: server umount lustre-OST0000 complete [ 5846.501372] Lustre: 3644:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789066430/real 1789066430] req@ffff88c6bf7c3480 x1875966101835648/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789066446 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5849.259507] Lustre: server umount lustre-OST0001 complete [ 5866.092400] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 5875.937488] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5876.460176] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5880.803489] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5888.433340] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5893.796573] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5896.971139] Lustre: 163287:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5903.778659] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5910.392807] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5914.292235] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:129) [ 5918.585275] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5918.813686] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5918.818945] Lustre: Skipped 2 previous similar messages [ 5921.914753] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:740 to 0x280000401:801) [ 5921.916527] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:739 to 0x2c0000401:801) [ 5924.353554] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5931.722102] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5935.284110] Lustre: 165158:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5943.409190] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 14:55:41 (1789066541) [ 5944.832564] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 6144 [ 5946.105352] Lustre: DEBUG MARKER: run for 4MB test file [ 5957.141528] Lustre: DEBUG MARKER: User quota (limit: 4 MB) [ 5962.428277] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 5963.895652] Lustre: DEBUG MARKER: Write half of file [ 5965.569810] Lustre: DEBUG MARKER: Write out of block quota ... [ 5967.195492] Lustre: DEBUG MARKER: Step1: done [ 5968.477160] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 5970.132688] Lustre: DEBUG MARKER: Step2: done [ 5991.813365] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 61440 [ 5993.153326] Lustre: DEBUG MARKER: run for 40MB test file [ 6003.192679] Lustre: DEBUG MARKER: User quota (limit: 40 MB) [ 6008.370250] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 6009.540596] Lustre: DEBUG MARKER: Write half of file [ 6011.999377] Lustre: DEBUG MARKER: Write out of block quota ... [ 6014.967457] Lustre: DEBUG MARKER: Step1: done [ 6016.445697] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 6017.847401] Lustre: DEBUG MARKER: Step2: done [ 6063.974374] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 14:57:41 (1789066661) [ 6103.502946] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 14:58:20 (1789066700) [ 6144.413487] Lustre: DEBUG MARKER: Write... [ 6146.619703] Lustre: DEBUG MARKER: Write out of block quota ... [ 6194.490483] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 14:59:51 (1789066791) [ 6200.729906] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 14:59:58 (1789066798) [ 6209.345068] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 15:00:07 (1789066807) [ 6216.924962] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 15:00:14 (1789066814) [ 6224.654214] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 15:00:22 (1789066822) [ 6277.578124] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 6401.178286] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 6541.699224] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 15:05:39 (1789067139) [ 6593.027750] Lustre: DEBUG MARKER: Restart... [ 6600.678362] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 6600.701274] 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 [ 6600.735347] Lustre: Skipped 7 previous similar messages [ 6600.752610] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6603.234687] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6603.255880] Lustre: Skipped 3 previous similar messages [ 6605.052227] Lustre: server umount lustre-MDT0000 complete [ 6608.355450] LustreError: 162148:0:(ldlm_lib.c:1199: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. [ 6608.378148] LustreError: 162148:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 11 previous similar messages [ 6609.025770] LustreError: 165892:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789067208 with bad export cookie 50129384280664236 [ 6609.027919] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6609.033874] LustreError: 165892:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 6609.252643] Lustre: server umount lustre-MDT0001 complete [ 6624.204052] Lustre: server umount lustre-OST0000 complete [ 6638.182242] Lustre: server umount lustre-OST0001 complete [ 6654.756270] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 6665.735408] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6666.236394] LustreError: 188269:0:(ldlm_lib.c:1199: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. [ 6666.352375] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6670.876871] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6678.605638] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6678.935051] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6683.220434] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6686.536228] Lustre: 189412:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 6694.979239] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6695.436754] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6703.215110] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6703.604627] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:161) [ 6710.768177] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:812 to 0x280000401:833) [ 6712.430050] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 6717.931950] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:810 to 0x2c0000401:833) [ 6718.792053] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6726.046740] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6729.215170] Lustre: 191284:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 6783.783406] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 15:09:41 (1789067381) [ 6839.676711] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 15:10:36 (1789067436) [ 8436.639206] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 15:37:13 (1789069033) [ 8450.531390] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 8450.536628] 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 [ 8450.545247] Lustre: Skipped 3 previous similar messages [ 8450.549820] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8451.556281] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8451.576707] Lustre: Skipped 3 previous similar messages [ 8454.271502] Lustre: server umount lustre-MDT0000 complete [ 8456.674398] LustreError: 195614:0:(ldlm_lib.c:1199: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. [ 8456.685513] LustreError: 195614:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 9 previous similar messages [ 8457.940464] LustreError: 188250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789069057 with bad export cookie 50129384280673343 [ 8457.948319] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8457.965731] LustreError: 188250:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 8458.510499] Lustre: server umount lustre-MDT0001 complete [ 8472.909443] Lustre: server umount lustre-OST0000 complete [ 8487.226493] Lustre: server umount lustre-OST0001 complete [ 8504.658782] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 8514.931050] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8515.421822] LustreError: 198895:0:(ldlm_lib.c:1199: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. [ 8515.556878] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8515.564714] Lustre: Skipped 1 previous similar message [ 8520.713556] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8529.875072] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8530.402226] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 8534.993346] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8537.657741] Lustre: 200041:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 8545.192379] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 8545.662947] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 8553.358634] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8554.857511] LustreError: 200395:0:(ldlm_lib.c:1199: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. [ 8554.876806] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:3 to 0x280000400:193) [ 8554.877017] LustreError: 200395:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [ 8561.145491] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:5836 to 0x280000401:5857) [ 8563.935522] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 8564.547235] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 8569.855144] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:5834 to 0x2c0000401:5857) [ 8572.938786] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8583.430322] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8587.540593] Lustre: 201915:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 8616.464767] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 15:40:14 (1789069214) [ 8648.175352] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 15:40:45 (1789069245) [ 8677.894879] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 15:41:15 (1789069275) [ 8714.329704] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 15:41:51 (1789069311) [ 8750.708889] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 15:42:27 (1789069347) [ 8832.260801] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 15:43:49 (1789069429) [ 8871.980621] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 15:44:29 (1789069469) [ 8948.024987] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 15:45:45 (1789069545) [ 8954.723706] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8954.725577] Lustre: Skipped 2 previous similar messages [ 8956.740703] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8956.742512] Lustre: Skipped 99 previous similar messages [ 8960.758372] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8960.764643] Lustre: Skipped 143 previous similar messages [ 8968.782354] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8968.786358] Lustre: Skipped 271 previous similar messages [ 8984.817129] Lustre: *** cfs_fail_loc=a09, val=0*** [ 8984.825495] Lustre: Skipped 651 previous similar messages [ 9016.840735] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9016.842721] Lustre: Skipped 1207 previous similar messages [ 9080.885772] Lustre: *** cfs_fail_loc=a09, val=0*** [ 9080.887616] Lustre: Skipped 2639 previous similar messages [ 9377.380411] Lustre: *** cfs_fail_loc=a08, val=0*** [ 9377.395103] Lustre: Skipped 2990 previous similar messages [ 9377.404282] Lustre: *** cfs_fail_loc=a08, val=0*** [ 9377.407065] Lustre: Skipped 7 previous similar messages [ 9528.806136] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 9528.815305] 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 [ 9528.824491] Lustre: Skipped 3 previous similar messages [ 9528.832693] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 9532.402364] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 9532.412311] Lustre: Skipped 3 previous similar messages [ 9534.645984] Lustre: server umount lustre-MDT0000 complete [ 9537.520413] LustreError: 202031:0:(ldlm_lib.c:1199: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. [ 9537.558599] LustreError: 202031:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 6 previous similar messages [ 9539.383097] LustreError: 198878:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789070139 with bad export cookie 50129384282451042 [ 9539.402765] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 9539.406354] LustreError: 198878:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 9542.627223] 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 [ 9542.628513] LustreError: 198891:0:(ldlm_lib.c:1199: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. [ 9542.628710] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 9542.642787] Lustre: Skipped 4 previous similar messages [ 9542.670498] LustreError: 198891:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 9544.673484] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 9544.681803] Lustre: Skipped 2 previous similar messages [ 9546.022241] Lustre: server umount lustre-MDT0001 complete [ 9550.636597] Lustre: server umount lustre-OST0000 complete [ 9555.104311] Lustre: server umount lustre-OST0001 complete [ 9562.448674] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_hostid [ 9573.236635] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 9623.296138] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [ 9634.865731] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 9635.178094] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 9635.202582] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 9635.322341] Lustre: lustre-MDT0000: new disk, initializing [ 9635.395652] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 9635.414620] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 9640.894849] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9651.333806] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 9651.444496] Lustre: 218621:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 9651.474721] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 9651.479932] Lustre: Skipped 1 previous similar message [ 9651.559372] Lustre: lustre-MDT0001: new disk, initializing [ 9651.628847] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 9651.674182] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 9651.686946] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 9656.733480] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9661.476982] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 9669.783733] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 9670.170229] Lustre: lustre-OST0000: new disk, initializing [ 9670.182179] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 9670.189899] Lustre: 220254:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 9670.289533] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 9671.786702] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 9671.803721] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 9671.975938] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 9679.087606] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9691.915033] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 9692.077161] Lustre: lustre-OST0001: new disk, initializing [ 9692.080832] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 9692.088335] Lustre: 221127:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 9692.163892] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 9693.828652] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 9693.836444] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 9693.889497] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 9698.051276] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 9709.066484] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 9713.828190] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 9745.219949] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 15:59:01 (1789070341) [ 9753.053592] Lustre: DEBUG MARKER: == sanity-quota test 49c: lfs quota long options don't consume an extra argument ========================================================== 15:59:10 (1789070350) [ 9760.424127] Lustre: DEBUG MARKER: == sanity-quota test 49d: lfs quota -d and --delimiter both work ========================================================== 15:59:17 (1789070357) [ 9766.647516] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 15:59:24 (1789070364) [ 9797.039374] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 15:59:54 (1789070394) [ 9844.387222] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 16:00:41 (1789070441) [ 9867.091048] Lustre: DEBUG MARKER: rename directory return 255 [ 9904.421951] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 16:01:41 (1789070501) [ 9926.906842] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 16:02:04 (1789070524) [ 9961.202510] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 16:02:38 (1789070558) [10100.634296] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 16:04:58 (1789070698) [10128.903450] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 16:05:26 (1789070726) [10167.543358] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 16:06:05 (1789070765) [10325.219492] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 16:08:42 (1789070922) [10332.640974] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [10332.646459] 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 [10332.664771] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10334.181860] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10334.185524] Lustre: Skipped 1 previous similar message [10338.067904] Lustre: server umount lustre-MDT0000 complete [10339.323646] LustreError: 219494:0:(ldlm_lib.c:1199: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. [10339.357133] LustreError: 219494:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [10342.349747] LustreError: 221126:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789070942 with bad export cookie 50129384282823232 [10342.354385] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10342.359612] LustreError: 221126:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [10342.898607] Lustre: server umount lustre-MDT0001 complete [10357.970583] Lustre: server umount lustre-OST0000 complete [10360.608488] Lustre: 3643:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789070944/real 1789070944] req@ffff88c588a16300 x1875966112883968/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789070960 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [10360.643222] 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 [10360.654557] Lustre: Skipped 3 previous similar messages [10361.864575] Lustre: server umount lustre-OST0001 complete [10387.505335] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [10400.441351] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10401.264530] LustreError: 238627:0:(ldlm_lib.c:1199: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. [10401.404309] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10401.419670] 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 [10406.880571] LustreError: 238628:0:(ldlm_lib.c:1199: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. [10407.009951] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10410.977891] LustreError: 238627:0:(ldlm_lib.c:1199: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. [10418.151254] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10418.659609] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [10418.681714] 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 [10424.287797] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10427.601952] Lustre: 239772:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10435.177967] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10435.488046] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [10435.512315] 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 [10443.654215] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10443.694040] LustreError: 240125:0:(ldlm_lib.c:1199: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. [10443.711865] LustreError: 240125:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [10445.737985] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:20 to 0x280000401:65) [10452.933199] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10453.239126] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [10453.250082] 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 [10458.610871] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:65) [10459.730754] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10468.811431] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10473.620773] Lustre: 241645:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10482.125759] LustreError: 238623:0:(osd_handler.c:3424:osd_quota_transfer()) lustre-MDT0000: quota transfer failed. Is project enforcement enabled on the ldiskfs filesystem? rc = -95 [10489.314133] 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 [10489.318344] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10489.338202] Lustre: Skipped 2 previous similar messages [10489.340544] Lustre: Skipped 1 previous similar message [10493.046663] Lustre: server umount lustre-MDT0000 complete [10494.435843] LustreError: 238622:0:(ldlm_lib.c:1199: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. [10494.463233] LustreError: 238622:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 8 previous similar messages [10498.257476] LustreError: 238608:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789071097 with bad export cookie 50129384282872127 [10498.281452] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10498.285498] LustreError: 238608:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 6 previous similar messages [10498.828401] Lustre: server umount lustre-MDT0001 complete [10513.555174] Lustre: server umount lustre-OST0000 complete [10515.691955] Lustre: 3641:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789071099/real 1789071099] req@ffff88c58d495f80 x1875966112944256/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789071115 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [10515.720322] 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 [10515.734591] Lustre: Skipped 1 previous similar message [10517.699296] Lustre: server umount lustre-OST0001 complete [10541.367594] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [10552.924313] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10553.575922] LustreError: 244036:0:(ldlm_lib.c:1199: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. [10553.673400] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10558.908655] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10568.155733] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10573.749292] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10577.189194] Lustre: 245183:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [10584.398582] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10592.038830] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10599.106366] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:67 to 0x280000401:97) [10601.666522] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [10607.109687] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:97) [10609.312983] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10617.623224] Lustre: DEBUG MARKER: Using TIMEOUT=20 [10621.593501] Lustre: 247062:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [10650.947242] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 16:14:08 (1789071248) [10706.577703] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [10709.116373] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 16:15:05 (1789071305) [10735.495533] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [10737.641559] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 16:15:34 (1789071334) [10789.802695] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [10791.691713] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 16:16:29 (1789071389) [10823.345546] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 16:17:00 (1789071420) [10834.459497] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [10839.954100] Lustre: 253532:0:(qsd_reint.c:249:qsd_reint_index()) lustre-OST0000: index version for fid [0x200000005:0x1008:0x0] is 0, but index isn't empty (1) [10844.728048] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [10849.759944] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [10853.215932] Lustre: DEBUG MARKER: Write... [10875.447901] LustreError: 254876:0:(mgs_handler.c:1144:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [10881.993882] Lustre: DEBUG MARKER: Write... [10897.164026] Lustre: DEBUG MARKER: Write... [10976.767108] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 16:19:34 (1789071574) [11003.371727] LustreError: 258891:0:(mgs_handler.c:1144:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [11045.678288] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 16:20:43 (1789071643) [11070.963474] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [11072.803683] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [11175.079166] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 16:22:52 (1789071772) [11224.027084] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 16:23:41 (1789071821) [11262.442602] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 16:24:19 (1789071859) [11274.006264] Lustre: DEBUG MARKER: User quota (block hardlimit:100 MB) [11297.815691] Lustre: DEBUG MARKER: Write... [11300.234114] Lustre: DEBUG MARKER: Write out of block quota ... [11403.318575] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 16:26:40 (1789072000) [11416.589971] Lustre: DEBUG MARKER: User quota (block hardlimit:1000 MB) [11444.685549] LustreError: 248255:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool2 id:60000 enforced:1 hard:10240 soft:0 granted:10240 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11506.535851] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 16:28:23 (1789072103) [11519.457224] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [11538.193683] Lustre: DEBUG MARKER: Write... [11540.055481] Lustre: DEBUG MARKER: Write out of block quota ... [11540.554906] LustreError: 244035:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:10240 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11597.091122] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 16:29:54 (1789072194) [11628.017514] Lustre: DEBUG MARKER: set to use default quota [11630.323039] Lustre: DEBUG MARKER: set default quota [11632.483451] Lustre: DEBUG MARKER: get default quota [11639.022372] Lustre: DEBUG MARKER: Test not out of quota [11643.473240] Lustre: DEBUG MARKER: Test out of quota [11655.636600] Lustre: DEBUG MARKER: Increase default quota [11679.001397] Lustre: DEBUG MARKER: Set quota to override default quota [11679.093839] LustreError: 244033:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:20480 soft:20480 granted:45056 time:1789677078 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11692.127572] Lustre: DEBUG MARKER: Set to use default quota again [11713.208354] Lustre: DEBUG MARKER: Cleanup [11778.565243] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 16:32:55 (1789072375) [11804.155953] Lustre: DEBUG MARKER: set default quota for qpool1 [11805.978321] Lustre: DEBUG MARKER: Write from user that hasn't lqe [11848.401356] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 16:34:05 (1789072445) [11931.903533] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 16:35:28 (1789072528) [12000.377477] Lustre: DEBUG MARKER: Write... [12004.134302] Lustre: DEBUG MARKER: Write out of block quota ... [12111.822835] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 16:38:29 (1789072709) [12146.159677] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 16:39:03 (1789072743) [12157.479812] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 16:39:14 (1789072754) [12201.270959] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 16:39:57 (1789072797) [12246.840832] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 16:40:44 (1789072844) [12273.758445] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 16:41:10 (1789072870) [12302.946775] Lustre: *** cfs_fail_loc=a06, val=0*** [12302.948429] Lustre: Skipped 6 previous similar messages [12303.235937] LustreError: 244050:0:(qmt_lock.c:479:qmt_lvbo_update()) $$$ failed to release quota space on glimpse 0!=2048 : rc = -11 [12303.235937] qmt:lustre-QMT0000 pool:dt-0x0 id:60000 enforced:1 hard:102400 soft:0 granted:25600 time:0 qunit: 16384 edquot:0 may_rel:0 revoke:0 default:no [12308.853028] Lustre: Failing over lustre-OST0001 [12309.177796] Lustre: server umount lustre-OST0001 complete [12312.060689] LustreError: lustre-OST0001-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [12312.070639] 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 [12312.072331] LustreError: Skipped 1 previous similar message [12312.072811] LustreError: 246598:0:(ldlm_lib.c:1199: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. [12312.072817] LustreError: 246598:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [12312.125536] Lustre: Skipped 1 previous similar message [12319.474409] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [12319.934988] Lustre: lustre-OST0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [12319.982530] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [12321.414414] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [12321.798972] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [12321.817431] Lustre: lustre-OST0001-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [12321.828827] Lustre: Skipped 7 previous similar messages [12326.421860] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12374.199960] LustreError: 3643:0:(qsd_reint.c:633:qqi_reint_delayed()) lustre-MDT0000: Delaying reintegration for qtype:0 until pending updates are flushed. [12378.664741] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 16:42:54 (1789072974) [12401.881866] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [12412.274257] LustreError: 297642:0:(qmt_pool.c:1407:qmt_pool_recalc()) cfs_fail_timeout id a07 sleeping for 10000ms [12416.994317] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [12416.997919] 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 [12417.004704] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [12417.008234] Lustre: Skipped 2 previous similar messages [12417.515776] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [12417.529167] Lustre: Skipped 3 previous similar messages [12419.764995] Lustre: lustre-MDT0000: Not available for connect from 192.168.206.24@tcp (stopping) [12422.329733] LustreError: 297642:0:(qmt_pool.c:1407:qmt_pool_recalc()) cfs_fail_timeout id a07 awake [12422.632028] LustreError: 244033:0:(ldlm_lib.c:1199: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. [12422.644182] LustreError: 244033:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 8 previous similar messages [12422.789758] Lustre: server umount lustre-MDT0000 complete [12431.980594] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [12432.090348] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [12432.368613] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [12432.373715] Lustre: Skipped 3 previous similar messages [12432.463276] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:112 to 0x280000401:129) [12432.466772] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:129) [12436.739641] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12437.495338] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [12437.508525] Lustre: Skipped 1 previous similar message [12475.180075] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 16:44:32 (1789073072) [12502.618395] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 16:44:59 (1789073099) [12527.332161] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 16:45:24 (1789073124) [12574.358520] Lustre: *** cfs_fail_loc=a08, val=0*** [12574.370830] Lustre: Skipped 2615 previous similar messages [12574.386870] Lustre: *** cfs_fail_loc=a08, val=0*** [12574.389612] Lustre: Skipped 4 previous similar messages [12670.890320] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 16:47:48 (1789073268) [12704.975133] LustreError: 244035:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:3072 soft:0 granted:3072 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [12765.946031] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 16:49:22 (1789073362) [12842.460173] LustreError: 244031:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1789678242 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [12996.181391] LustreError: 245241:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1789678395 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [13154.876864] LustreError: 244033:0:(qmt_entry.c:558:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:1000 enforced:1 hard:2048 soft:2048 granted:16384 time:1789678554 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [13289.991988] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 16:58:07 (1789073887) [13296.412545] LustreError: 3644:0:(qsd_reint.c:633:qqi_reint_delayed()) lustre-MDT0001: Delaying reintegration for qtype:0 until pending updates are flushed. [13297.465625] Lustre: *** cfs_fail_loc=a09, val=0*** [13297.469626] Lustre: Skipped 1 previous similar message [13305.530618] Lustre: *** cfs_fail_loc=a09, val=0*** [13305.534048] Lustre: Skipped 281 previous similar messages [13321.541787] Lustre: *** cfs_fail_loc=a09, val=0*** [13321.547078] Lustre: Skipped 609 previous similar messages [13372.118177] Lustre: lustre-MDT0000: Not available for connect from 192.168.206.24@tcp (stopping) [13372.395857] 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 [13372.423605] Lustre: Skipped 4 previous similar messages [13377.230877] LustreError: 244032:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13377.249390] LustreError: 244032:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 6 previous similar messages [13377.391294] Lustre: server umount lustre-MDT0000 complete [13382.307646] LustreError: 244031:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [13382.330455] LustreError: 244031:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 4 previous similar messages [13386.352632] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13386.495133] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13386.730322] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13386.786839] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:132 to 0x280000401:161) [13386.791391] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:161) [13391.219571] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13391.850685] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [13391.855717] Lustre: Skipped 2 previous similar messages [13391.864129] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [13410.049087] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 17:00:07 (1789074007) [13411.872933] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [13413.614624] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 17:00:11 (1789074011) [13446.424306] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 17:00:43 (1789074043) [13467.862244] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 17:01:05 (1789074065) [13490.833396] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 17:01:28 (1789074088) [13509.605632] 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 [13509.608262] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [13509.608608] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [13509.617464] Lustre: Skipped 4 previous similar messages [13509.634202] Lustre: Skipped 7 previous similar messages [13512.628186] Lustre: server umount lustre-MDT0000 complete [13514.725223] LustreError: 245241:0:(ldlm_lib.c:1199: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. [13514.739454] LustreError: 245241:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 7 previous similar messages [13516.723961] LustreError: 244018:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789074116 with bad export cookie 50129384283976692 [13516.735573] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13516.736087] LustreError: 244018:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [13519.841962] 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 [13519.847202] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [13519.853978] Lustre: Skipped 2 previous similar messages [13521.895668] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [13521.902208] Lustre: Skipped 2 previous similar messages [13527.013144] LustreError: 279234:0:(ldlm_lib.c:1199: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. [13527.017316] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [13527.037640] LustreError: 279234:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [13527.043431] Lustre: Skipped 1 previous similar message [13531.104763] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [13531.516806] Lustre: server umount lustre-MDT0001 complete [13550.048138] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [13550.160604] Lustre: server umount lustre-OST0000 complete [13561.208069] Lustre: server umount lustre-OST0001 complete [13568.480822] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_hostid [13576.168425] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [13618.559163] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13618.852950] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [13618.899635] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [13618.962938] Lustre: lustre-MDT0000: new disk, initializing [13619.108439] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13619.146644] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [13622.785027] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13632.785390] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [13641.662869] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13642.145071] Lustre: lustre-OST0000: new disk, initializing [13642.147307] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [13642.155636] Lustre: Skipped 1 previous similar message [13642.167594] Lustre: 316176:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13642.277887] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [13644.018762] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [13644.039514] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [13644.097668] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [13651.695507] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13666.779423] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [13676.621031] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13676.758879] Lustre: lustre-OST0001: new disk, initializing [13676.764711] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [13676.773936] Lustre: 317235:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13676.839619] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [13678.548821] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [13678.572319] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [13678.647884] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [13685.001412] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13696.681379] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [13713.112737] Lustre: lustre-MDT0000: Not available for connect from 192.168.206.24@tcp (stopping) [13714.408934] 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 [13714.433064] Lustre: Skipped 1 previous similar message [13719.491605] Lustre: server umount lustre-MDT0000 complete [13731.284483] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13731.384842] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13731.807085] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13734.889421] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [13734.900269] Lustre: Skipped 3 previous similar messages [13736.385528] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13744.302544] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [13745.911284] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [13747.541734] LustreError: 318915:0:(qmt_entry.c:1150:qmt_map_lge_idx()) qmt: cannot map ostidx 0, num_used 1: rc = -22 [13749.808098] LustreError: 318915:0:(qmt_entry.c:1150:qmt_map_lge_idx()) qmt: cannot map ostidx 0, num_used 1: rc = -22 [13752.679342] Lustre: server umount lustre-MDT0000 complete [13759.423157] LustreError: 315171:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789074359 with bad export cookie 50129384283979359 [13759.434357] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [13769.946554] Lustre: server umount lustre-OST0000 complete [13771.744866] Lustre: 3643:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789074355/real 1789074355] req@ffff88c58561ce00 x1875966116702848/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789074371 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [13771.767461] 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 [13774.206791] Lustre: server umount lustre-OST0001 complete [13794.443608] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_hostid [13802.687413] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [13851.663441] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing load_modules_local [13862.707804] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13862.965249] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [13863.016852] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [13863.104815] Lustre: lustre-MDT0000: new disk, initializing [13863.182357] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [13863.199946] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [13867.579601] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13879.256189] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [13879.340555] Lustre: 323728:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [13879.373550] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [13879.377923] Lustre: Skipped 1 previous similar message [13879.452408] Lustre: lustre-MDT0001: new disk, initializing [13879.551916] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [13879.568381] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [13884.104586] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13889.003582] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [13896.520967] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13896.877399] Lustre: lustre-OST0000: new disk, initializing [13896.884918] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [13896.896089] Lustre: 325359:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13896.955284] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [13896.964033] Lustre: Skipped 1 previous similar message [13898.284063] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [13898.309313] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [13898.448940] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [13903.725154] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13911.995830] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [13912.111718] Lustre: 326230:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [13913.691379] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [13913.738549] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [13916.854762] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [13926.469325] Lustre: DEBUG MARKER: Using TIMEOUT=20 [13930.165285] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [13938.064178] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 17:08:55 (1789074535) [13956.364966] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 17:09:13 (1789074553) [13979.978350] Lustre: *** cfs_fail_loc=170c, val=0*** [14032.710213] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 17:10:29 (1789074629) [14067.683333] 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 [14067.684549] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [14067.703505] Lustre: Skipped 1 previous similar message [14067.713425] Lustre: Skipped 6 previous similar messages [14072.477605] Lustre: server umount lustre-MDT0000 complete [14072.801673] LustreError: 323735:0:(ldlm_lib.c:1199: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. [14072.827985] LustreError: 323735:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [14080.177738] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14080.301717] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14080.464121] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [14080.473669] Lustre: Skipped 1 previous similar message [14080.511489] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:33) [14084.988712] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14085.617949] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [14085.624359] Lustre: Skipped 1 previous similar message [14085.642201] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14095.845193] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14095.848355] 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 [14095.870866] Lustre: Skipped 4 previous similar messages [14100.354760] Lustre: server umount lustre-MDT0000 complete [14105.756099] LustreError: 323734:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.24@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [14105.769473] LustreError: 323734:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 11 previous similar messages [14107.062832] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14107.164333] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14107.460979] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:65) [14111.104315] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14112.763836] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [14117.632891] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 17:11:55 (1789074715) [14140.988983] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 17:12:18 (1789074738) [14173.602185] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 17:12:51 (1789074771) [14175.737705] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 OST is too small, skip the test [14177.371831] Lustre: DEBUG MARKER: == sanity-quota test 97a: LQA control commands =========== 17:12:55 (1789074775) [14209.987214] LustreError: 337002:0:(qmt_lqa.c:79:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-dt-lqa1: rc = -2 [14209.994313] LustreError: 337002:0:(qmt_lqa.c:84:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-md-lqa1: rc = -2 [14212.291475] Lustre: DEBUG MARKER: == sanity-quota test 97b: Check LQA internals ============ 17:13:29 (1789074809) [14237.596245] LustreError: 337898:0:(qmt_lqa.c:250:qmt_lqa_insert_range()) lustre-QMT0000: LQA range 15-31 partially overlaps with existing range 10-19: rc = -34 [14237.610567] LustreError: 337898:0:(qmt_lqa.c:669:qmt_lqa_add()) lustre-QMT0000: lqa:lqa1 can't add range 15:31: rc = -17 [14241.443113] LustreError: 338095:0:(qmt_lqa.c:825:qmt_lqa_remove()) lustre-QMT0000: lqa-md-lqa1 cannot remove range 10:19: rc = -2 [14251.586267] Lustre: DEBUG MARKER: adding 50 LQA ranges took 2s [14257.058462] Lustre: DEBUG MARKER: Removing 50 LQA ranges took 2s [14266.403988] Lustre: DEBUG MARKER: == sanity-quota test 97c: LQA lfs quota commands and MDS restart consistency ========================================================== 17:14:23 (1789074863) [14271.000965] Lustre: Failing over lustre-MDT0000 [14271.415766] Lustre: server umount lustre-MDT0000 complete [14271.461964] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14271.462701] 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 [14271.481410] LustreError: 323739:0:(ldlm_lib.c:1199: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. [14271.490804] Lustre: Skipped 2 previous similar messages [14271.526844] LustreError: 323739:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 7 previous similar messages [14282.225640] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14282.426037] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14282.857820] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [14282.863200] Lustre: Skipped 1 previous similar message [14282.921835] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [14284.961148] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [14287.797356] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14287.871323] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [14287.882400] Lustre: Skipped 7 previous similar messages [14287.894605] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [14287.944817] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:97) [14293.859481] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [14302.879624] Lustre: DEBUG MARKER: == sanity-quota test 97d: LQA disk persistence using standard commands ========================================================== 17:15:00 (1789074900) [14317.728058] Lustre: Failing over lustre-MDT0000 [14318.143623] Lustre: server umount lustre-MDT0000 complete [14326.486874] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [14326.653535] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14327.067980] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [14331.037595] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [14332.170250] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [14332.443102] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [14332.517779] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:129) [14338.065553] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [14371.911692] Lustre: DEBUG MARKER: == sanity-quota test 97e: LQA add/remove should reject invalid ranges ========================================================== 17:16:09 (1789074969) [14385.221957] LustreError: 344237:0:(qmt_lqa.c:79:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-dt-lqa1: rc = -2 [14385.244622] LustreError: 344237:0:(qmt_lqa.c:84:qmt_lqa_destroy()) lustre-QMT0000: cannot destroy lqa-md-lqa1: rc = -2 [14387.092719] Lustre: DEBUG MARKER: == sanity-quota test 98: Verify MDT retry on -EDQUOT during mkdir ========================================================== 17:16:24 (1789074984) [14392.992511] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [14394.776914] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [14400.485546] Lustre: DEBUG MARKER: oleg624-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0001-mdc-*.mds_server_uuid 1475 0 [14402.265358] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [14408.548747] Lustre: *** cfs_fail_loc=a02, val=1*** [14408.550774] LustreError: 323733:0:(lod_object.c:6285:lod_declare_create()) lustre-MDT0000-mdtlov: Injecting -EDQUOT for directory create on MDT0000 (fail_val=1): rc = -122 [14417.280995] Lustre: DEBUG MARKER: == sanity-quota test 300: inode quota with MDT directory migration at 80% limit ========================================================== 17:16:54 (1789075014) [14435.406249] Lustre: DEBUG MARKER: Creating 819 files as quota_usr ... [14449.342410] Lustre: DEBUG MARKER: Migrating directory from MDT0 to MDT1 ... [14510.300748] Lustre: DEBUG MARKER: Migration completed successfully [14545.761070] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 14283 sec ======== 17:19:03 (1789075143) [14547.802565] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 17:19:05 (1789075145) === [14552.429103] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 17:19:09 (1789075149) === [14562.786347] 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 [14562.794416] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [14562.805369] Lustre: Skipped 8 previous similar messages [14562.805661] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [14562.823802] Lustre: Skipped 9 previous similar messages [14567.476076] Lustre: server umount lustre-MDT0000 complete [14567.905625] LustreError: 324611:0:(ldlm_lib.c:1199: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. [14567.936843] LustreError: 324611:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 23 previous similar messages [14575.978188] LustreError: 326229:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789075175 with bad export cookie 50129384283985897 [14575.979382] LustreError: MGC192.168.206.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [14575.985036] LustreError: 326229:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [14576.292954] Lustre: server umount lustre-MDT0001 complete [14594.336360] Lustre: 3641:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789075177/real 1789075177] req@ffff88c5856ae680 x1875966118807168/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789075193 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14595.497662] Lustre: server umount lustre-OST0000 complete [14595.552387] Lustre: 3643:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789075179/real 1789075179] req@ffff88c5856ac700 x1875966118807424/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789075195 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14598.499653] Lustre: 3641:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789075182/real 1789075182] req@ffff88c5861c6300 x1875966118807680/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789075198 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14601.703973] Lustre: 3642:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789075185/real 1789075185] req@ffff88c5856afb80 x1875966118808064/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789075201 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [14604.606872] Lustre: server umount lustre-OST0001 complete [14624.559365] Lustre: DEBUG MARKER: oleg624-server.virtnet: executing unload_modules_local [14627.787612] Key type lgssc unregistered [14628.178603] LNet: 349315:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [14628.190987] LNetError: 349315:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [14628.230923] LNet: Removed LNI 192.168.206.124@tcp [14629.361252] Key type .llcrypt unregistered [14629.362909] Key type ._llcrypt unregistered