[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 647183875 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001012] APIC: Switch to symmetric I/O mode setup [ 0.003080] x2apic enabled [ 0.004005] Switched APIC routing to physical x2apic. [ 0.005033] kvm-guest: setup PV IPIs [ 0.008000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008017] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009009] pid_max: default: 32768 minimum: 301 [ 0.010162] LSM: Security Framework initializing [ 0.011051] Yama: becoming mindful. [ 0.012128] SELinux: Initializing. [ 0.013084] *** VALIDATE selinux *** [ 0.023453] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.029000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.030037] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031107] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.032120] *** VALIDATE tmpfs *** [ 0.034425] *** VALIDATE proc *** [ 0.035265] *** VALIDATE cgroup *** [ 0.036009] *** VALIDATE cgroup2 *** [ 0.037257] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038137] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040027] Spectre V2 : User space: Vulnerable [ 0.041006] Speculative Store Bypass: Vulnerable [ 0.044460] debug: unmapping init [mem 0xffffffff96e59000-0xffffffff96e60fff] [ 0.046487] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.047831] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.048020] ... version: 2 [ 0.049015] ... bit width: 48 [ 0.050012] ... generic registers: 4 [ 0.051022] ... value mask: 0000ffffffffffff [ 0.052025] ... max period: 00007fffffffffff [ 0.053011] ... fixed-purpose events: 3 [ 0.054011] ... event mask: 000000070000000f [ 0.055262] rcu: Hierarchical SRCU implementation. [ 0.057595] smp: Bringing up secondary CPUs ... [ 0.058806] x86: Booting SMP configuration: [ 0.059019] .... node #0, CPUs: #1 #2 #3 [ 0.067184] smp: Brought up 1 node, 4 CPUs [ 0.069011] smpboot: Max logical packages: 1 [ 0.070010] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.114300] node 0 deferred pages initialised in 42ms [ 0.118551] devtmpfs: initialized [ 0.119223] x86/mm: Memory block size: 128MB [ 0.122387] gcov: version magic: 0x41383552 [ 0.124433] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.125128] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.126371] pinctrl core: initialized pinctrl subsystem [ 0.127196] [ 0.127689] ************************************************************* [ 0.128014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.129016] ** ** [ 0.130029] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.131014] ** ** [ 0.132017] ** This means that this kernel is built to expose internal ** [ 0.133013] ** IOMMU data structures, which may compromise security on ** [ 0.134011] ** your system. ** [ 0.135010] ** ** [ 0.136011] ** If you see this message and you are not debugging the ** [ 0.137014] ** kernel, report this immediately to your vendor! ** [ 0.138137] ** ** [ 0.139014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.140010] ************************************************************* [ 0.142000] NET: Registered protocol family 16 [ 0.143523] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.144052] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.145053] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.146647] cpuidle: using governor menu [ 0.149130] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.152703] PCI: Using configuration type 1 for base access [ 0.154249] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.165298] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.167063] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.171120] cryptd: max_cpu_qlen set to 1000 [ 0.172198] ACPI: Added _OSI(Module Device) [ 0.173000] ACPI: Added _OSI(Processor Device) [ 0.174054] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.176013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.183257] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.190669] ACPI: Interpreter enabled [ 0.191049] ACPI: PM: (supports S0 S3 S4 S5) [ 0.192011] ACPI: Using IOAPIC for interrupt routing [ 0.193087] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.194457] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.208473] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.209050] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.210020] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.211063] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.213815] acpiphp: Slot [2] registered [ 0.214098] acpiphp: Slot [5] registered [ 0.215357] acpiphp: Slot [6] registered [ 0.216273] acpiphp: Slot [7] registered [ 0.217353] acpiphp: Slot [8] registered [ 0.218258] acpiphp: Slot [9] registered [ 0.219089] acpiphp: Slot [10] registered [ 0.220268] acpiphp: Slot [3] registered [ 0.221227] acpiphp: Slot [4] registered [ 0.222089] acpiphp: Slot [11] registered [ 0.223094] acpiphp: Slot [12] registered [ 0.224093] acpiphp: Slot [13] registered [ 0.225090] acpiphp: Slot [14] registered [ 0.226172] acpiphp: Slot [15] registered [ 0.227159] acpiphp: Slot [16] registered [ 0.228158] acpiphp: Slot [17] registered [ 0.229166] acpiphp: Slot [18] registered [ 0.230082] acpiphp: Slot [19] registered [ 0.231098] acpiphp: Slot [20] registered [ 0.232153] acpiphp: Slot [21] registered [ 0.233104] acpiphp: Slot [22] registered [ 0.234088] acpiphp: Slot [23] registered [ 0.235184] acpiphp: Slot [24] registered [ 0.236112] acpiphp: Slot [25] registered [ 0.237091] acpiphp: Slot [26] registered [ 0.238093] acpiphp: Slot [27] registered [ 0.239099] acpiphp: Slot [28] registered [ 0.240108] acpiphp: Slot [29] registered [ 0.241118] acpiphp: Slot [30] registered [ 0.242129] acpiphp: Slot [31] registered [ 0.243060] PCI host bridge to bus 0000:00 [ 0.244021] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.245026] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.246023] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.247021] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.248022] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.249027] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.250182] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.253258] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.255931] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.262645] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.265058] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.266017] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.267018] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.268021] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.270223] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.272488] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.273043] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.275000] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.282014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.297013] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.304013] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.314210] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.326015] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.335017] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.353016] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.355000] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.367013] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.375060] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.398017] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.408373] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.413015] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.421017] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.436020] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.443706] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.449016] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.454015] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.471281] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.482118] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.491018] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.497014] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.527017] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.560611] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.573014] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.585016] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.612015] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.632272] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.637545] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.642375] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.646611] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.650240] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.656081] iommu: Default domain type: Passthrough [ 0.657000] SCSI subsystem initialized [ 0.658124] ACPI: bus type USB registered [ 0.660109] usbcore: registered new interface driver usbfs [ 0.663101] usbcore: registered new interface driver hub [ 0.666103] usbcore: registered new device driver usb [ 0.669174] pps_core: LinuxPPS API ver. 1 registered [ 0.672025] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.676267] PTP clock support registered [ 0.680049] EDAC MC: Ver: 3.0.0 [ 0.682009] PCI: Using ACPI for IRQ routing [ 0.682623] NetLabel: Initializing [ 0.684016] NetLabel: domain hash size = 128 [ 0.688013] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.694088] NetLabel: unlabeled traffic allowed by default [ 0.697357] vgaarb: loaded [ 0.700124] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.703030] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.713182] clocksource: Switched to clocksource kvm-clock [ 0.847483] VFS: Disk quotas dquot_6.6.0 [ 0.849494] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.852911] *** VALIDATE ramfs *** [ 0.854511] *** VALIDATE hugetlbfs *** [ 0.856620] pnp: PnP ACPI init [ 0.859869] pnp: PnP ACPI: found 6 devices [ 0.877350] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.881803] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.884616] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.887482] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.890782] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.893953] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.897818] NET: Registered protocol family 2 [ 0.900895] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.906950] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.911396] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.917352] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.922759] TCP: Hash tables configured (established 65536 bind 65536) [ 0.926480] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.931132] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.934982] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.939088] NET: Registered protocol family 1 [ 0.942438] RPC: Registered named UNIX socket transport module. [ 0.945421] RPC: Registered udp transport module. [ 0.947721] RPC: Registered tcp transport module. [ 0.949964] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.953174] NET: Registered protocol family 44 [ 0.955340] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.958620] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.961906] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.965586] PCI: CLS 0 bytes, default 64 [ 0.968236] Unpacking initramfs... [ 3.248959] debug: unmapping init [mem 0xffff97df3cc54000-0xffff97df3ffbffff] [ 3.256798] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 3.261344] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 3.267446] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 4.163773] Initialise system trusted keyrings [ 4.166133] Key type blacklist registered [ 4.168504] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 4.178506] zbud: loaded [ 4.181973] *** VALIDATE nfs *** [ 4.183616] *** VALIDATE nfs4 *** [ 4.185884] pstore: using deflate compression [ 4.190775] Platform Keyring initialized [ 4.307881] NET: Registered protocol family 38 [ 4.310461] Key type asymmetric registered [ 4.312874] Asymmetric key parser 'x509' registered [ 4.316120] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 4.320514] io scheduler mq-deadline registered [ 4.322467] io scheduler kyber registered [ 4.324278] io scheduler bfq registered [ 4.327795] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 4.332123] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 4.336402] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 4.340797] ACPI: Power Button [PWRF] [ 4.347297] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 4.355974] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 4.383671] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 4.396528] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 4.424502] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 4.453599] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 4.493209] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 4.498594] Non-volatile memory driver v1.3 [ 4.500786] Linux agpgart interface v0.103 [ 4.537176] virtio_blk virtio1: [vda] 134096 512-byte logical blocks (68.7 MB/65.5 MiB) [ 4.542779] vda: detected capacity change from 0 to 68657152 [ 4.568258] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 4.573759] vdb: detected capacity change from 0 to 1073741824 [ 4.597888] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.601863] vdc: detected capacity change from 0 to 2621440000 [ 4.629308] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 4.633737] vdd: detected capacity change from 0 to 2621440000 [ 4.650362] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.654860] vde: detected capacity change from 0 to 4294967296 [ 4.676172] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 4.681783] vdf: detected capacity change from 0 to 4294967296 [ 4.692192] libphy: Fixed MDIO Bus: probed [ 4.702181] usbcore: registered new interface driver usbserial_generic [ 4.705536] usbserial: USB Serial support registered for generic [ 4.711113] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 4.716262] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 4.718592] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 4.722291] mousedev: PS/2 mouse device common for all mice [ 4.726934] rtc_cmos 00:05: RTC can wake from S4 [ 4.730444] rtc_cmos 00:05: registered as rtc0 [ 4.732691] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 4.738137] intel_pstate: CPU model not supported [ 4.742635] hid: raw HID events driver (C) Jiri Kosina [ 4.745323] usbcore: registered new interface driver usbhid [ 4.745831] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 4.751484] usbhid: USB HID core driver [ 4.757089] drop_monitor: Initializing network drop monitor service [ 4.760164] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 4.765067] Initializing XFRM netlink socket [ 4.765463] NET: Registered protocol family 10 [ 4.770991] Segment Routing with IPv6 [ 4.772081] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 4.782878] NET: Registered protocol family 17 [ 4.785383] mpls_gso: MPLS GSO support [ 4.792259] RAS: Correctable Errors collector initialized. [ 4.795425] AVX version of gcm_enc/dec engaged. [ 4.797785] AES CTR mode by8 optimization enabled [ 4.891182] sched_clock: Marking stable (4891122770, 0)->(6266813600, -1375690830) [ 4.896544] registered taskstats version 1 [ 4.899565] Loading compiled-in X.509 certificates [ 4.902861] zswap: loaded using pool lzo/zbud [ 4.930218] Key type big_key registered [ 4.943547] Key type encrypted registered [ 4.946354] ima: No TPM chip found, activating TPM-bypass! [ 4.949471] ima: Allocated hash algorithm: sha1 [ 4.952301] ima: No architecture policies found [ 4.954882] evm: Initialising EVM extended attributes: [ 4.957884] evm: security.selinux [ 4.959943] evm: security.ima [ 4.961867] evm: security.capability [ 4.964120] evm: HMAC attrs: 0x1 [ 4.967524] rtc_cmos 00:05: setting system clock to 2026-01-16 06:55:34 UTC (1768546534) [ 4.981809] debug: unmapping init [mem 0xffffffff97e03000-0xffffffff97ffffff] [ 4.988763] debug: unmapping init [mem 0xffffffff96b82000-0xffffffff96e58fff] [ 5.000174] Write protecting the kernel read-only data: 28672k [ 5.007073] debug: unmapping init [mem 0xffffffff95203000-0xffffffff953fffff] [ 5.011237] debug: unmapping init [mem 0xffffffff95b14000-0xffffffff95bfffff] [ 5.067849] 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) [ 5.086357] systemd[1]: Detected virtualization kvm. [ 5.092186] systemd[1]: Detected architecture x86-64. [ 5.095220] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 5.138707] systemd[1]: No hostname configured. [ 5.141145] systemd[1]: Set hostname to . [ 5.146174] random: systemd: uninitialized urandom read (16 bytes read) [ 5.153777] systemd[1]: Initializing machine ID from random generator. [ 5.284592] random: ln: uninitialized urandom read (6 bytes read) [ 5.438332] random: systemd: uninitialized urandom read (16 bytes read) [ 5.442512] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 5.451184] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 5.465577] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Swap. [ OK ] Reached target Slices. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Timers. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 6.924916] device-mapper: uevent: version 1.0.3 [ 6.927208] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target S[ 8.090517] virtio_net virtio0 ens2: renamed from eth0 ystem Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 8.345708] random: fast init done [ 9.056355] scsi host0: ata_piix [ 9.494164] scsi host1: ata_piix [ 9.496426] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 9.500089] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 14.474806] random: crng init done [ 14.476318] random: 7 urandom warning(s) missed due to ratelimiting [ 15.309835] dracut-initqueue[585]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 17.151360] 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 Initrd Root Device. [ OK ] Stopped target Timers. [ OK ] Stopped target Remote File Systems. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 19.893374] printk: systemd: 25 output lines suppressed due to ratelimiting [ 20.309226] SELinux: Disabled at runtime. [ 20.384878] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 20.400680] systemd[1]: Detected virtualization kvm. [ 20.403130] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 21.902975] systemd[1]: initrd-switch-root.service: Succeeded. [ 21.907768] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 21.923662] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 21.930166] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 21.938427] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 21.950525] systemd[1]: Starting Journal Service... Starting Journal Service... [ 21.963872] systemd[1]: Activating swap /dev/disk/by-label/SWAP... Activating swap /dev/disk/by-label/SWAP... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 22.022782] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Stopped target Switch Root. [ OK ] Created slice User and Session Slice. Starting Remount Root and Kernel File Systems... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Stopped target Initrd Root File System. [ OK ] Created slice system-sshd\x2dkeygen.slice. Starting Apply Kernel Variables... Mounting Kernel Debug File System... [ OK ] Created slice system-getty.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. Mounting POSIX Message Queue File System... [ OK ] Reached target Local Encrypted Volumes. 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. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Reached target rpc_pipefs.target. [ OK ] Reached target Slices. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Stopped target Initrd File Systems. [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ 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 ] Started Apply Kernel Variables. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 23.021431] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 23.750789] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 23.944935] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 26.448602] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 26.776666] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (6s / no limit) [** ] A start job is running for Configur…-only root support (7s / no limit)[ 29.664048] Key type dns_resolver registered [*** ] A start job is running for Configur…-only root support (8s / no limit)[ 30.057478] NFS: Registering the id_resolver key type [ 30.059583] Key type id_resolver registered [ 30.061021] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... 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 update of the root trust anchor for DNSSEC. [ OK ] Started dnf makecache --timer. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started irqbalance daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... [ 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... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started Login Service. [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg342-server login: [ 71.203832] libcfs: loading out-of-tree module taints kernel. [ 71.225672] Key type ._llcrypt registered [ 71.226967] Key type .llcrypt registered [ 71.279313] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_hostid [ 83.778302] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 84.569821] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 84.577973] alg: No test for adler32 (adler32-zlib) [ 85.611425] Lustre: Lustre: Build Version: 2.17.50_30_gbb2e37c [ 86.010185] LNet: Added LNI 192.168.203.142@tcp [8/256/0/180] [ 87.631157] Key type lgssc registered [ 88.332043] Lustre: Echo OBD driver; http://www.lustre.org/ [ 98.190662] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 121.068519] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 128.433072] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 128.467862] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 129.659383] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 129.687559] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 129.754789] Lustre: lustre-MDT0000: new disk, initializing [ 129.825935] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 129.834816] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 132.056692] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 139.784591] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 139.838486] Lustre: 6497:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 139.860169] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 139.866229] Lustre: Skipped 1 previous similar message [ 139.912886] Lustre: lustre-MDT0001: new disk, initializing [ 139.945651] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 139.958409] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 139.966950] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 141.987857] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 144.855201] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 149.579099] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 149.708894] Lustre: lustre-OST0000: new disk, initializing [ 149.713164] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 149.760853] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 149.977791] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 149.987100] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 150.076681] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 152.525217] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 159.724797] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 159.821361] Lustre: lustre-OST0001: new disk, initializing [ 159.824050] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 159.852942] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 163.500417] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 165.359862] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 165.368184] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 165.394283] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 171.795384] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 177.245368] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 185.767501] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing check_logdir /tmp/testlogs/ [ 188.741482] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing yml_node [ 191.481568] Lustre: DEBUG MARKER: Client: 2.17.50.30 [ 193.251522] Lustre: DEBUG MARKER: MDS: 2.17.50.30 [ 194.910255] Lustre: DEBUG MARKER: OSS: 2.17.50.30 [ 196.144674] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Fri Jan 16 01:58:44 EST 2026 [ 199.773688] hrtimer: interrupt took 4964832 ns [ 211.583557] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 212.845796] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 [ 215.155923] Lustre: DEBUG MARKER: === sanity-quota: start setup 01:59:03 (1768546743) === [ 217.875761] Lustre: DEBUG MARKER: oleg342-client.virtnet: executing check_config_client /mnt/lustre [ 231.104961] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 233.461442] Lustre: 13267:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 236.031668] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 239.710395] Lustre: DEBUG MARKER: === sanity-quota: finish setup 01:59:27 (1768546767) === [ 268.212050] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 01:59:56 (1768546796) [ 298.763621] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 02:00:27 (1768546827) [ 305.798243] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 309.083141] Lustre: DEBUG MARKER: Write... [ 310.503101] Lustre: DEBUG MARKER: Write out of block quota ... [ 332.278460] Lustre: DEBUG MARKER: -------------------------------------- [ 333.397927] Lustre: DEBUG MARKER: Group quota (block hardlimit:10 MB) [ 336.983657] Lustre: DEBUG MARKER: Write... [ 338.401642] Lustre: DEBUG MARKER: Write out of block quota ... [ 362.187366] Lustre: DEBUG MARKER: -------------------------------------- [ 363.055139] Lustre: DEBUG MARKER: Project quota (block hardlimit:10 mb) [ 364.326863] Lustre: DEBUG MARKER: Write... [ 365.352086] Lustre: DEBUG MARKER: Write out of block quota ... [ 397.899054] Lustre: DEBUG MARKER: == sanity-quota test 1b: Quota pools: Block hard limit (normal use and out of quota) ========================================================== 02:02:06 (1768546926) [ 403.229266] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 414.561907] Lustre: DEBUG MARKER: Write... [ 415.875751] Lustre: DEBUG MARKER: Write out of block quota ... [ 437.891335] Lustre: DEBUG MARKER: -------------------------------------- [ 438.710779] Lustre: DEBUG MARKER: Group quota (block hardlimit:20 MB) [ 441.351628] Lustre: DEBUG MARKER: Write... [ 442.389753] Lustre: DEBUG MARKER: Write out of block quota ... [ 465.301974] Lustre: DEBUG MARKER: -------------------------------------- [ 466.251819] Lustre: DEBUG MARKER: Project quota (block hardlimit:20 mb) [ 467.742235] Lustre: DEBUG MARKER: Write... [ 469.003748] Lustre: DEBUG MARKER: Write out of block quota ... [ 505.080421] Lustre: DEBUG MARKER: == sanity-quota test 1c: Quota pools: check 3 pools with hardlimit only for global ========================================================== 02:03:53 (1768547033) [ 510.948737] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 527.561803] Lustre: DEBUG MARKER: Write... [ 529.116538] Lustre: DEBUG MARKER: Write out of block quota ... [ 575.564948] Lustre: DEBUG MARKER: == sanity-quota test 1d: Quota pools: check block hardlimit on different pools ========================================================== 02:05:04 (1768547104) [ 580.356396] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 593.640759] Lustre: DEBUG MARKER: Write... [ 594.528102] Lustre: DEBUG MARKER: Write out of block quota ... [ 643.403846] Lustre: DEBUG MARKER: == sanity-quota test 1e: Quota pools: global pool high block limit vs quota pool with small ========================================================== 02:06:11 (1768547171) [ 648.994827] Lustre: DEBUG MARKER: User quota (block hardlimit:53000000 MB) [ 656.304739] Lustre: DEBUG MARKER: Write... [ 657.161537] Lustre: DEBUG MARKER: Write out of block quota ... [ 664.553207] Lustre: DEBUG MARKER: Write... [ 689.911568] Lustre: DEBUG MARKER: == sanity-quota test 1f: Quota pools: correct qunit after removing/adding OST ========================================================== 02:06:58 (1768547218) [ 694.690421] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 701.307236] Lustre: DEBUG MARKER: Write... [ 702.201230] Lustre: DEBUG MARKER: Write out of block quota ... [ 724.420098] Lustre: DEBUG MARKER: Write... [ 725.328756] Lustre: DEBUG MARKER: Write out of block quota ... [ 753.413696] Lustre: DEBUG MARKER: == sanity-quota test 1g: Quota pools: Block hard limit with wide striping ========================================================== 02:08:01 (1768547281) [ 758.341683] Lustre: DEBUG MARKER: User quota (block hardlimit:40 MB) [ 766.760507] Lustre: 6504:0:(osd_handler.c:2197:osd_trans_start()) lustre-MDT0000: credits 6546 > trans_max 3200 [ 766.765027] Lustre: 6504:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 4/16/0, destroy: 0/0/0 [ 766.769216] Lustre: 6504:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 401/401/0, xattr_set: 602/5615/0 [ 766.772942] Lustre: 6504:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 20/118/0, punch: 0/0/0, quota 8/328/0 [ 766.775910] Lustre: 6504:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/68/0, delete: 0/0/0 [ 766.779420] Lustre: 6504:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 766.782160] CPU: 3 PID: 6504 Comm: mdt00_001 Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #2 [ 766.784970] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 766.787447] Call Trace: [ 766.788297] ? dump_stack+0xbb/0x10e [ 766.789401] ? osd_trans_start+0x8db/0x9d0 [osd_ldiskfs] [ 766.791512] ? top_trans_start+0x599/0xd80 [ptlrpc] [ 766.793137] ? lod_ref_add+0x30/0x30 [lod] [ 766.794138] ? lod_trans_start+0x109/0x4c0 [lod] [ 766.795273] ? mdd_declare_attr_set+0x190/0x690 [mdd] [ 766.796483] ? mdd_env_info+0x25/0xc0 [mdd] [ 766.797614] ? mdd_trans_start+0x18/0x30 [mdd] [ 766.798766] ? mdd_attr_set+0xa5a/0x1250 [mdd] [ 766.800243] ? mdt_reint_setattr+0x1342/0x1f90 [mdt] [ 766.801847] ? mdt_reint_setattr+0x1342/0x1f90 [mdt] [ 766.803110] ? mdt_reint_rec+0x139/0x2b0 [mdt] [ 766.804356] ? mdt_reint_internal+0x6a0/0xdc0 [mdt] [ 766.806056] ? mdt_reint+0x163/0x190 [mdt] [ 766.807524] ? tgt_handle_request0+0x137/0xaf0 [ptlrpc] [ 766.809561] ? tgt_request_handle+0x573/0x1e70 [ptlrpc] [ 766.812191] ? ptlrpc_server_handle_request+0x443/0x13b0 [ptlrpc] [ 766.814621] ? lprocfs_counter_add+0x15b/0x210 [obdclass] [ 766.816553] ? ptlrpc_main+0xce8/0x1400 [ptlrpc] [ 766.818266] ? ptlrpc_wait_event+0x980/0x980 [ptlrpc] [ 766.819662] ? kthread+0x1d1/0x200 [ 766.822293] ? set_kthread_struct+0x70/0x70 [ 766.823614] ? ret_from_fork+0x1f/0x30 [ 767.623305] Lustre: DEBUG MARKER: Write... [ 771.968903] Lustre: DEBUG MARKER: Write out of block quota ... [ 807.656711] Lustre: DEBUG MARKER: == sanity-quota test 1h: Block hard limit test using fallocate ========================================================== 02:08:56 (1768547336) [ 812.376876] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 814.561288] Lustre: DEBUG MARKER: Write 5MiB Using Fallocate [ 818.246693] Lustre: DEBUG MARKER: Write 11MiB Using Fallocate [ 890.782647] Lustre: DEBUG MARKER: == sanity-quota test 1i: Quota pools: different limit and usage relations ========================================================== 02:10:16 (1768547416) [ 923.345333] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 937.310778] Lustre: DEBUG MARKER: Write... [ 939.304477] Lustre: DEBUG MARKER: Write out of block quota ... [ 966.654045] Lustre: DEBUG MARKER: Write... [ 968.534679] Lustre: DEBUG MARKER: Write out of block quota ... [ 977.322698] LustreError: 6505:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:10240 soft:0 granted:15360 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 1014.231146] Lustre: DEBUG MARKER: == sanity-quota test 1j: Enable project quota enforcement for root ========================================================== 02:12:21 (1768547541) [ 1030.393234] Lustre: DEBUG MARKER: -------------------------------------- [ 1032.006824] Lustre: DEBUG MARKER: Project quota (hardlimit: 40 mb, 2048 files) [ 1324.148396] Lustre: DEBUG MARKER: SKIP: sanity-quota test_2 skipping excluded test 2 [ 1326.548776] Lustre: DEBUG MARKER: == sanity-quota test 3a: Block soft limit (start timer, timer goes off, stop timer) ========================================================== 02:17:33 (1768547853) [ 1372.979873] Lustre: DEBUG MARKER: Write after timer goes off [ 1378.157171] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1447.234788] Lustre: DEBUG MARKER: Write after timer goes off [ 1449.200069] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1516.169542] Lustre: DEBUG MARKER: Write after timer goes off [ 1522.991488] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1586.492591] Lustre: DEBUG MARKER: == sanity-quota test 3b: Quota pools: Block soft limit (start timer, expires, stop timer) ========================================================== 02:21:54 (1768548114) [ 1637.868958] Lustre: DEBUG MARKER: Write after timer goes off [ 1642.436799] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1722.896784] Lustre: DEBUG MARKER: Write after timer goes off [ 1728.919785] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1796.025997] Lustre: DEBUG MARKER: Write after timer goes off [ 1802.428398] Lustre: DEBUG MARKER: Write after cancel lru locks [ 1879.710591] Lustre: DEBUG MARKER: == sanity-quota test 3c: Quota pools: check block soft limit on different pools ========================================================== 02:26:47 (1768548407) [ 1939.540794] Lustre: DEBUG MARKER: Write after timer goes off [ 1941.213556] Lustre: DEBUG MARKER: Write after cancel lru locks [ 2006.582866] Lustre: DEBUG MARKER: SKIP: sanity-quota test_4a skipping excluded test 4a [ 2008.256609] Lustre: DEBUG MARKER: == sanity-quota test 4b: Grace time strings handling ===== 02:28:55 (1768548535) [ 2018.167776] Lustre: DEBUG MARKER: == sanity-quota test 5: Chown [ 2109.355964] Lustre: DEBUG MARKER: == sanity-quota test 6: Test dropping acquire request on master ========================================================== 02:30:37 (1768548637) [ 2139.498824] Lustre: *** cfs_fail_loc=513, val=601*** [ 2140.129701] Lustre: *** cfs_fail_loc=513, val=601*** [ 2140.131395] Lustre: Skipped 4 previous similar messages [ 2141.132642] Lustre: *** cfs_fail_loc=513, val=601*** [ 2141.134363] Lustre: Skipped 4 previous similar messages [ 2141.407838] LustreError: 6506:0:(service.c:2319:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1854455537904256 [ 2144.616141] Lustre: *** cfs_fail_loc=513, val=601*** [ 2144.623530] Lustre: Skipped 33 previous similar messages [ 2149.736295] Lustre: *** cfs_fail_loc=513, val=601*** [ 2149.738157] Lustre: Skipped 19 previous similar messages [ 2156.002222] Lustre: 8386:0:(service.c:1607:ptlrpc_at_send_early_reply()) @@@ Could not add any time (5/5), not sending early reply req@ffff97df852c6680 x1854455529843584/t0(0) o4->779e0269-dc70-45ad-9131-3a6aba60531a@192.168.203.42@tcp:450/0 lens 488/448 e 1 to 0 dl 1768548690 ref 2 fl Interpret:/600/0 rc 0/0 job:'dd.60000' uid:60000 gid:60000 projid:0 [ 2156.511185] Lustre: 18597:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768548670/real 1768548670] req@ffff97de822b4380 x1854455537904256/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1768548686 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 2156.543520] 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 [ 2156.573030] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 2156.587663] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2156.768242] LustreError: 6506:0:(service.c:2319:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1854455537913344 [ 2157.801287] Lustre: *** cfs_fail_loc=513, val=601*** [ 2157.804350] Lustre: Skipped 45 previous similar messages [ 2173.407440] Lustre: 3653:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768548686/real 1768548686] req@ffff97de85413480 x1854455537913344/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1768548702 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 2173.439766] 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 [ 2173.456346] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 2173.471824] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2175.336237] Lustre: *** cfs_fail_loc=513, val=601*** [ 2175.344619] Lustre: Skipped 86 previous similar messages [ 2176.499136] LustreError: 6506:0:(service.c:2319:ptlrpc_server_handle_req_in()) drop incoming rpc opc 601, x1854455537923456 [ 2192.863491] Lustre: 18597:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768548706/real 1768548706] req@ffff97dfb4ca7b80 x1854455537923456/t0(0) o601->lustre-MDT0000-lwp-OST0000@0@lo:23/10 lens 336/336 e 0 to 1 dl 1768548722 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'ll_ost_io00_003.0' uid:0 gid:0 projid:4294967295 [ 2192.897586] 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 [ 2192.906850] Lustre: lustre-MDT0000: Client lustre-MDT0000-lwp-OST0000_UUID (at 0@lo) reconnecting [ 2192.913262] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2229.103785] Lustre: DEBUG MARKER: == sanity-quota test 7a: Quota reintegration (global index) ========================================================== 02:32:36 (1768548756) [ 2252.545910] Lustre: Failing over lustre-OST0000 [ 2252.618978] LustreError: 74639:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 2252.736308] Lustre: server umount lustre-OST0000 complete [ 2254.313856] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 2254.317671] 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 [ 2254.336535] Lustre: Skipped 1 previous similar message [ 2259.427551] LustreError: 40042:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2259.450759] LustreError: 40042:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 2262.382378] LustreError: 40042:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2264.558155] LustreError: 8381:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2264.572322] LustreError: 8381:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 2265.506904] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2265.908252] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 2265.956512] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2267.169255] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 2267.576687] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 2267.576708] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2272.497378] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2280.134330] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2285.720291] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2290.943114] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2295.807454] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2301.126978] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2306.816295] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2328.124069] Lustre: Failing over lustre-OST0000 [ 2328.178158] LustreError: 78097:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 2328.182228] LustreError: 78097:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2328.291190] Lustre: server umount lustre-OST0000 complete [ 2328.958489] LustreError: 40042:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2329.074897] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2329.080823] 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 [ 2329.085753] LustreError: Skipped 2 previous similar messages [ 2334.064928] LustreError: 8383:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2334.095994] LustreError: 8383:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 2335.954359] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2336.530802] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 2336.556238] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2337.815957] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 2337.909909] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 2337.911865] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2337.935025] Lustre: Skipped 1 previous similar message [ 2343.973947] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2353.356980] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2359.315722] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2365.292318] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2370.253355] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2376.454870] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2382.568874] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2405.692898] Lustre: DEBUG MARKER: == sanity-quota test 7b: Quota reintegration (slave index) ========================================================== 02:35:33 (1768548933) [ 2435.054832] Lustre: *** cfs_fail_loc=a02, val=0*** [ 2440.795696] LustreError: 3654:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -5, flags:0x8 qsd:lustre-OST0000 qtype:usr id:60000 enforced:1 granted: 1024 pending:0 waiting:0 req:1 usage: 2048 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 2440.815460] Lustre: Failing over lustre-OST0000 [ 2440.842118] LustreError: 82981:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 2440.844836] LustreError: 82981:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2440.873138] Lustre: server umount lustre-OST0000 complete [ 2441.610515] LustreError: 8383:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2444.271561] 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 [ 2444.281444] Lustre: Skipped 1 previous similar message [ 2448.249891] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2448.479954] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 2448.501511] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2449.938801] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 2450.084058] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 2450.084909] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 2450.094340] Lustre: Skipped 1 previous similar message [ 2455.123359] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2463.572203] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2468.387791] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2473.595798] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2479.115429] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2484.530430] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2489.989592] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2519.726279] Lustre: DEBUG MARKER: == sanity-quota test 7c: Quota reintegration (restart mds during reintegration) ========================================================== 02:37:27 (1768549047) [ 2541.607797] LustreError: 87660:0:(qsd_reint.c:475:qsd_reint_main()) cfs_fail_timeout id a03 sleeping for 10000ms [ 2543.490658] Lustre: Failing over lustre-MDT0000 [ 2543.797884] LustreError: 87762:0:(obd_class.h:479:obd_check_dev()) Device 26 not setup [ 2543.802695] LustreError: 87762:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2544.028949] LustreError: 6504:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2544.044021] LustreError: 6504:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 2544.163645] Lustre: server umount lustre-MDT0000 complete [ 2545.634886] 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 [ 2545.648889] Lustre: Skipped 4 previous similar messages [ 2547.311299] LustreError: 87664:0:(qsd_reint.c:475:qsd_reint_main()) cfs_fail_timeout interrupted [ 2553.588922] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2553.719734] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2554.077950] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2554.132532] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2554.216239] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2558.386551] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2559.470267] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2559.475482] Lustre: Skipped 1 previous similar message [ 2559.479071] LustreError: 3650:0:(ldlm_resource.c:981:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x2020000:0x0].0x0 (ffff97df8a1b8300) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 2559.526767] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 2559.561030] Lustre: 87665:0:(qsd_reint.c:241:qsd_reint_index()) lustre-OST0001: index version for fid [0x200000005:0x100c:0x0] is 0, but index isn't empty (1) [ 2559.598529] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:139 to 0x280000401:161) [ 2559.602210] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:120 to 0x2c0000401:161) [ 2566.735750] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2660.292378] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2665.297960] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2670.760481] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2676.118378] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2682.466250] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2712.541775] Lustre: DEBUG MARKER: == sanity-quota test 7d: Quota reintegration (Transfer index in multiple bulks) ========================================================== 02:40:40 (1768549240) [ 2734.737648] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 2739.965776] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 2772.864247] Lustre: DEBUG MARKER: == sanity-quota test 7e: Quota reintegration (inode limits) ========================================================== 02:41:40 (1768549300) [ 2795.302494] Lustre: Failing over lustre-MDT0001 [ 2795.501371] LustreError: 96974:0:(obd_class.h:479:obd_check_dev()) Device 25 not setup [ 2795.510659] LustreError: 96974:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2795.664274] Lustre: server umount lustre-MDT0001 complete [ 2799.602476] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 2799.614849] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2799.635251] LustreError: 6508:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2799.662302] LustreError: 6508:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 2807.078188] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2807.492417] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2807.534077] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2809.571463] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2811.891711] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2812.916386] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2812.930878] Lustre: Skipped 3 previous similar messages [ 2812.973326] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 2813.058868] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 2818.555723] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2822.994481] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 2828.274976] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2835.154791] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 2840.271261] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2846.078860] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 2910.755600] Lustre: Failing over lustre-MDT0001 [ 2910.945791] LustreError: 100127:0:(obd_class.h:479:obd_check_dev()) Device 21 not setup [ 2910.951244] LustreError: 100127:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2911.055984] Lustre: server umount lustre-MDT0001 complete [ 2911.634183] LustreError: 20876:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2911.642648] LustreError: 20876:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 2915.300862] 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 [ 2915.301029] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 2915.318939] Lustre: Skipped 2 previous similar messages [ 2920.948776] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2922.472627] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2922.565163] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2923.908879] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2927.220906] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2927.587603] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2927.590810] Lustre: Skipped 2 previous similar messages [ 2927.616550] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 2927.706968] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 2935.778481] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2941.846432] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 2946.834584] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2952.307148] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 2957.860860] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2964.060502] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 3035.292757] Lustre: DEBUG MARKER: == sanity-quota test 8: Run dbench with quota enabled ==== 02:46:03 (1768549563) [ 3223.250407] Lustre: DEBUG MARKER: == sanity-quota test 9: Block limit larger than 4GB (b10707) ========================================================== 02:49:10 (1768549750) [ 3225.021615] Lustre: DEBUG MARKER: OST0_SIZE: 3604112 required: 4900000 [ 3231.311687] Lustre: DEBUG MARKER: == sanity-quota test 10: Test quota for root user ======== 02:49:19 (1768549759) [ 3269.369383] Lustre: DEBUG MARKER: == sanity-quota test 11: Chown/chgrp ignores quota ======= 02:49:56 (1768549796) [ 3304.028661] Lustre: DEBUG MARKER: == sanity-quota test 12a: Block quota rebalancing ======== 02:50:31 (1768549831) [ 3366.180579] Lustre: DEBUG MARKER: == sanity-quota test 12b: Inode quota rebalancing ======== 02:51:33 (1768549893) [ 3486.410714] Lustre: DEBUG MARKER: == sanity-quota test 13: Cancel per-ID lock in the LRU list ========================================================== 02:53:33 (1768550013) [ 3535.247070] Lustre: DEBUG MARKER: == sanity-quota test 14: check panic in qmt_site_recalc_cb ========================================================== 02:54:22 (1768550062) [ 3558.847147] Lustre: Failing over lustre-OST0000 [ 3558.903114] LustreError: 113510:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 3558.906450] LustreError: 113510:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 3558.983532] Lustre: server umount lustre-OST0000 complete [ 3562.468892] 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 [ 3562.481051] Lustre: Skipped 2 previous similar messages [ 3562.486502] LustreError: 104018:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3562.502994] LustreError: 104018:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 3572.308394] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3572.661848] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 3572.693464] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3574.131189] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3574.622992] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3574.628778] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3574.666589] Lustre: Skipped 2 previous similar messages [ 3578.958579] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3608.603722] Lustre: DEBUG MARKER: == sanity-quota test 15: Set over 4T block quota ========= 02:55:36 (1768550136) [ 3630.132343] Lustre: DEBUG MARKER: == sanity-quota test 16a: lfs quota should skip the inactive MDT/OST ========================================================== 02:55:57 (1768550157) [ 3651.265370] Lustre: lustre-MDT0001: Client 779e0269-dc70-45ad-9131-3a6aba60531a (at 192.168.203.42@tcp) reconnecting [ 3669.242973] Lustre: DEBUG MARKER: == sanity-quota test 16b: lfs quota should skip the nonexistent MDT/OST ========================================================== 02:56:37 (1768550197) [ 3670.955539] Lustre: DEBUG MARKER: SKIP: sanity-quota test_16b needs >= 3 MDTs [ 3672.969695] Lustre: DEBUG MARKER: == sanity-quota test 17: DQACQ return recoverable error == 02:56:40 (1768550200) [ 3690.198458] Lustre: *** cfs_fail_loc=a04, val=37*** [ 3690.204685] LustreError: 104008:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1056 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 3691.279789] Lustre: *** cfs_fail_loc=a04, val=37*** [ 3691.283194] LustreError: 104008:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1056 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 3693.429727] Lustre: *** cfs_fail_loc=a04, val=37*** [ 3693.443897] LustreError: 104008:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -37, flags:0x1 qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1056 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 3743.055228] Lustre: *** cfs_fail_loc=a04, val=11*** [ 3794.767079] Lustre: *** cfs_fail_loc=a04, val=110*** [ 3794.802494] Lustre: Skipped 2 previous similar messages [ 3848.831185] Lustre: *** cfs_fail_loc=a04, val=107*** [ 3848.835475] Lustre: Skipped 2 previous similar messages [ 3910.957666] Lustre: DEBUG MARKER: == sanity-quota test 18: MDS failover while writing, no watchdog triggered (b14840) ========================================================== 03:00:38 (1768550438) [ 3923.673172] Lustre: DEBUG MARKER: User quota (limit: 200) [ 3928.481265] Lustre: DEBUG MARKER: Write 100M (buffered) ... [ 3937.316843] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3939.396046] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 3941.987415] Lustre: Failing over lustre-MDT0000 [ 3942.347223] LustreError: 126038:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 3942.358403] LustreError: 126038:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 3942.434124] Lustre: server umount lustre-MDT0000 complete [ 3942.818197] LustreError: 20876:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3942.849337] LustreError: 20876:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 3942.904446] LustreError: lustre-MDT0000-lwp-OST0000: operation quota_acquire to node 0@lo failed: rc = -107 [ 3942.916054] 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 [ 3942.937632] Lustre: Skipped 1 previous similar message [ 3945.952355] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3961.765030] Lustre: 3654:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768550475/real 1768550475] req@ffff97dfb82d7480 x1854455540155776/t0(0) o400->MGC192.168.203.142@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1768550491 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3961.800206] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3964.197630] LDISKFS-fs (dm-0): 7 truncates cleaned up [ 3964.199411] LDISKFS-fs (dm-0): recovery complete [ 3964.217203] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3972.065546] LustreError: 3650:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff97dfb819c380 x1854455540165504/t0(0) o250->MGC192.168.203.142@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 [ 3972.391059] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3972.432244] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3973.497037] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3977.436636] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3977.701039] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3977.719858] Lustre: Skipped 1 previous similar message [ 3977.806871] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 3977.849563] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:654 to 0x2c0000401:673) [ 3977.849868] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:658 to 0x280000401:673) [ 3985.751269] Lustre: DEBUG MARKER: oleg342-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3987.561497] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3993.303472] Lustre: DEBUG MARKER: (dd_pid=109208, time=0, timeout=600) [ 4028.193335] Lustre: DEBUG MARKER: User quota (limit: 200) [ 4032.798223] Lustre: DEBUG MARKER: Write 100M (directio) ... [ 4040.857793] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4042.540433] Lustre: DEBUG MARKER: Fail mds for 40 seconds [ 4044.306817] Lustre: Failing over lustre-MDT0000 [ 4044.519299] LustreError: 129129:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 4044.524436] LustreError: 129129:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 4044.752799] Lustre: server umount lustre-MDT0000 complete [ 4047.842518] LustreError: lustre-MDT0000-lwp-OST0001: operation ldlm_enqueue to node 0@lo failed: rc = -107 [ 4047.855143] LustreError: Skipped 1 previous similar message [ 4064.741965] Lustre: 3651:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768550578/real 1768550578] req@ffff97de895ac700 x1854455540220544/t0(0) o400->MGC192.168.203.142@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1768550594 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4064.783070] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4067.069068] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 4067.072601] LDISKFS-fs (dm-0): recovery complete [ 4067.081490] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4075.001175] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x69128096a196e0ef [ 4075.435864] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4075.475578] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4076.919827] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4080.618600] LustreError: 3650:0:(ldlm_resource.c:981:ldlm_resource_complain()) lustre-MDT0000-lwp-OST0001: namespace resource [0x200000006:0x20000:0x0].0x0 (ffff97df92267400) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 4080.649370] LustreError: 3650:0:(ldlm_resource.c:981:ldlm_resource_complain()) Skipped 5 previous similar messages [ 4080.743218] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 4080.750307] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4080.794967] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:675 to 0x280000401:705) [ 4080.798235] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:654 to 0x2c0000401:705) [ 4088.777733] Lustre: DEBUG MARKER: oleg342-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4090.869578] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4096.513693] Lustre: DEBUG MARKER: (dd_pid=111607, time=0, timeout=600) [ 4134.413592] Lustre: DEBUG MARKER: == sanity-quota test 19: Updating admin limits doesn't zero operational limits(b14790) ========================================================== 03:04:21 (1768550661) [ 4178.201942] Lustre: DEBUG MARKER: == sanity-quota test 20: Test if setquota specifiers work properly (b15754) ========================================================== 03:05:05 (1768550705) [ 4199.700223] Lustre: DEBUG MARKER: == sanity-quota test 21: Setquota while writing [ 4212.726447] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for user: quota_usr [ 4214.439515] Lustre: DEBUG MARKER: Set limit(block:10G; file:1000000) for group: quota_usr [ 4216.432954] Lustre: DEBUG MARKER: Set limit(block:10G; file:) for project: 1000 [ 4219.363769] Lustre: DEBUG MARKER: Set quota for 1 times [ 4223.477445] Lustre: DEBUG MARKER: Set quota for 2 times [ 4226.639914] Lustre: DEBUG MARKER: Set quota for 3 times [ 4230.926400] Lustre: DEBUG MARKER: Set quota for 4 times [ 4235.400404] Lustre: DEBUG MARKER: Set quota for 5 times [ 4240.568408] Lustre: DEBUG MARKER: Set quota for 6 times [ 4245.366555] Lustre: DEBUG MARKER: Set quota for 7 times [ 4296.191693] Lustre: DEBUG MARKER: == sanity-quota test 22: enable/disable quota by 'lctl conf_param/set_param -P' ========================================================== 03:07:03 (1768550823) [ 4316.130936] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4316.146239] Lustre: Skipped 3 previous similar messages [ 4319.499914] LustreError: 135968:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 4319.513565] LustreError: 135968:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 4319.867567] Lustre: server umount lustre-MDT0000 complete [ 4324.176506] LustreError: 6488:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768550853 with bad export cookie 7571255308007694575 [ 4324.176657] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4324.203402] LustreError: 6488:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 4324.495955] Lustre: server umount lustre-MDT0001 complete [ 4339.207188] LustreError: 136371:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 4339.225542] LustreError: 136371:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 4339.505119] Lustre: server umount lustre-OST0000 complete [ 4342.176287] Lustre: 3652:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768550855/real 1768550855] req@ffff97dfbf69a300 x1854455540410496/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768550871 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4344.884187] Lustre: server umount lustre-OST0001 complete [ 4361.264565] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 4372.907894] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4373.598461] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4377.874648] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4390.198079] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4390.721450] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4395.882094] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4399.024477] Lustre: 138865:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4406.437872] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4407.209294] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4414.434458] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4419.521232] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:708 to 0x280000401:737) [ 4423.898475] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4424.251066] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 4425.675591] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:97) [ 4425.708449] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:707 to 0x2c0000401:737) [ 4431.353723] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4439.449434] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4443.544876] Lustre: 140715:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4470.244570] 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 [ 4470.248577] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4470.259825] Lustre: Skipped 15 previous similar messages [ 4470.279261] Lustre: Skipped 3 previous similar messages [ 4474.108051] LustreError: 141519:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 4474.123935] LustreError: 141519:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 4474.386234] Lustre: server umount lustre-MDT0000 complete [ 4475.363327] LustreError: 137740:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4475.390713] LustreError: 137740:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 80 previous similar messages [ 4478.822924] LustreError: 137726:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768551008 with bad export cookie 7571255308007700840 [ 4478.843584] LustreError: 137726:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 4478.870533] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4479.310337] Lustre: server umount lustre-MDT0001 complete [ 4493.951766] Lustre: server umount lustre-OST0000 complete [ 4496.863142] Lustre: 3653:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768551010/real 1768551010] req@ffff97de822a1f80 x1854455540496768/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768551026 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4497.559786] Lustre: server umount lustre-OST0001 complete [ 4514.030642] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 4525.019221] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4525.689377] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4530.414540] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4540.623544] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4546.415267] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4549.527275] Lustre: 144401:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4556.339209] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4563.612768] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4570.989310] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:708 to 0x280000401:769) [ 4573.879995] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4574.284152] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 4574.292744] Lustre: Skipped 2 previous similar messages [ 4576.288244] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:129) [ 4576.304819] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:707 to 0x2c0000401:769) [ 4581.256539] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4589.548424] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4593.253618] Lustre: 146245:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4610.427640] Lustre: DEBUG MARKER: == sanity-quota test 23: Quota should be honored with directIO (b16125) ========================================================== 03:12:18 (1768551138) [ 4612.511510] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 6144 [ 4614.246671] Lustre: DEBUG MARKER: run for 4MB test file [ 4626.267928] Lustre: DEBUG MARKER: User quota (limit: 4 MB) [ 4630.637061] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 4632.083930] Lustre: DEBUG MARKER: Write half of file [ 4633.925252] Lustre: DEBUG MARKER: Write out of block quota ... [ 4635.817704] Lustre: DEBUG MARKER: Step1: done [ 4637.416926] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 4639.207229] Lustre: DEBUG MARKER: Step2: done [ 4663.563183] Lustre: DEBUG MARKER: OST0_SIZE: 3605396 required: 61440 [ 4665.313715] Lustre: DEBUG MARKER: run for 40MB test file [ 4678.566393] Lustre: DEBUG MARKER: User quota (limit: 40 MB) [ 4685.442373] Lustre: DEBUG MARKER: Step1: trigger EDQUOT with O_DIRECT [ 4687.447222] Lustre: DEBUG MARKER: Write half of file [ 4690.986365] Lustre: DEBUG MARKER: Write out of block quota ... [ 4694.739270] Lustre: DEBUG MARKER: Step1: done [ 4696.148262] Lustre: DEBUG MARKER: Step2: rewrite should succeed [ 4697.936175] Lustre: DEBUG MARKER: Step2: done [ 4750.063862] Lustre: DEBUG MARKER: == sanity-quota test 24: lfs draws an asterix when limit is reached (b16646) ========================================================== 03:14:37 (1768551277) [ 4794.305468] Lustre: DEBUG MARKER: == sanity-quota test 25: check indexes versions ========== 03:15:21 (1768551321) [ 4835.139288] Lustre: DEBUG MARKER: Write... [ 4838.145895] Lustre: DEBUG MARKER: Write out of block quota ... [ 4888.134908] Lustre: DEBUG MARKER: == sanity-quota test 27a: lfs quota/setquota should handle wrong arguments (b19612) ========================================================== 03:16:55 (1768551415) [ 4895.309918] Lustre: DEBUG MARKER: == sanity-quota test 27b: lfs quota/setquota should handle user/group/project ID (b20200) ========================================================== 03:17:02 (1768551422) [ 4905.701300] Lustre: DEBUG MARKER: == sanity-quota test 27c: lfs quota should support human-readable output ========================================================== 03:17:13 (1768551433) [ 4914.799665] Lustre: DEBUG MARKER: == sanity-quota test 27d: lfs setquota should support fraction block limit ========================================================== 03:17:22 (1768551442) [ 4923.077601] Lustre: DEBUG MARKER: == sanity-quota test 30: Hard limit updates should not reset grace times ========================================================== 03:17:30 (1768551450) [ 4974.022299] Lustre: DEBUG MARKER: == sanity-quota test 33: Basic usage tracking for user [ 5074.302835] Lustre: DEBUG MARKER: == sanity-quota test 34: Usage transfer for user [ 5185.400605] Lustre: DEBUG MARKER: == sanity-quota test 35: Usage is still accessible across reboot ========================================================== 03:21:53 (1768551713) [ 5224.856897] Lustre: DEBUG MARKER: Restart... [ 5232.614487] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5232.625119] 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 [ 5232.641227] Lustre: Skipped 1 previous similar message [ 5232.648980] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5234.663318] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5234.682077] Lustre: Skipped 3 previous similar messages [ 5236.359329] LustreError: 164665:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 5236.370387] LustreError: 164665:0:(obd_class.h:479:obd_check_dev()) Skipped 25 previous similar messages [ 5236.598133] Lustre: server umount lustre-MDT0000 complete [ 5239.785384] LustreError: 143290:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5239.798239] LustreError: 143290:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 5240.012162] LustreError: 144778:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768551769 with bad export cookie 7571255308007703143 [ 5240.020292] LustreError: 144778:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5240.027196] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5240.386365] Lustre: server umount lustre-MDT0001 complete [ 5255.203295] LustreError: 165067:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 5255.208826] LustreError: 165067:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 5255.404564] Lustre: server umount lustre-OST0000 complete [ 5269.696222] Lustre: server umount lustre-OST0001 complete [ 5286.931795] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 5297.069798] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5297.837580] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5302.212388] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5311.782901] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5312.428868] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5317.566900] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5320.786853] Lustre: 167550:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5327.597516] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5334.072089] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5342.103723] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5342.253806] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5342.256699] Lustre: Skipped 1 previous similar message [ 5343.273351] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:781 to 0x280000401:801) [ 5343.275052] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:777 to 0x2c0000401:801) [ 5343.356245] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:161) [ 5349.436209] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5357.193378] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5360.335884] Lustre: 169396:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5415.244490] Lustre: DEBUG MARKER: == sanity-quota test 37: Quota accounted properly for file created by 'lfs setstripe' ========================================================== 03:25:42 (1768551942) [ 5470.274479] Lustre: DEBUG MARKER: == sanity-quota test 38: Quota accounting iterator doesn't skip id entries ========================================================== 03:26:37 (1768551997) [ 6940.380972] Lustre: DEBUG MARKER: == sanity-quota test 39: Project ID interface works correctly ========================================================== 03:51:07 (1768553467) [ 6950.880627] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 6950.883834] 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 [ 6950.901041] Lustre: Skipped 3 previous similar messages [ 6950.908653] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6956.514581] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6956.522439] Lustre: Skipped 7 previous similar messages [ 6956.854396] LustreError: 174521:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 6956.863932] LustreError: 174521:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 6957.211428] Lustre: server umount lustre-MDT0000 complete [ 6961.491044] LustreError: 173212:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768553491 with bad export cookie 7571255308007712264 [ 6961.493603] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6961.510096] LustreError: 173212:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 6961.632338] LustreError: 171108:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6961.651060] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 6961.658682] LustreError: 171108:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 6961.688431] LustreError: 174723:0:(obd_class.h:479:obd_check_dev()) Device 18 not setup [ 6961.694627] LustreError: 174723:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 6961.822250] Lustre: server umount lustre-MDT0001 complete [ 6967.885124] LustreError: 174923:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 6967.888132] LustreError: 174923:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 6968.214435] Lustre: server umount lustre-OST0000 complete [ 6972.573753] Lustre: server umount lustre-OST0001 complete [ 6989.374266] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 7001.182640] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7001.919862] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7006.360855] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7015.024925] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7015.697094] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 7021.333288] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7024.880763] Lustre: 177406:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 7032.890871] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7033.487413] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 7040.679513] LustreError: 177761:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7040.718963] LustreError: 177761:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 7041.187638] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7047.162868] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:5803 to 0x280000401:5825) [ 7051.217301] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7051.445749] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 7052.759196] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:5803 to 0x2c0000401:5825) [ 7052.759598] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:193) [ 7058.811248] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7066.916187] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7070.630326] Lustre: 179252:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 7102.386705] Lustre: DEBUG MARKER: == sanity-quota test 40a: Hard link across different project ID ========================================================== 03:53:50 (1768553630) [ 7127.429376] Lustre: DEBUG MARKER: == sanity-quota test 40b: Mv across different project ID ========================================================== 03:54:15 (1768553655) [ 7154.562642] Lustre: DEBUG MARKER: == sanity-quota test 40c: Remote child Dir inherit project quota properly ========================================================== 03:54:41 (1768553681) [ 7187.292244] Lustre: DEBUG MARKER: == sanity-quota test 40d: Stripe Directory inherit project quota properly ========================================================== 03:55:14 (1768553714) [ 7218.486696] Lustre: DEBUG MARKER: == sanity-quota test 41: df should return projid-specific values ========================================================== 03:55:46 (1768553746) [ 7287.338502] Lustre: DEBUG MARKER: == sanity-quota test 42: lfs quota should include default quota info ========================================================== 03:56:55 (1768553815) [ 7317.845204] Lustre: DEBUG MARKER: == sanity-quota test 48: lfs quota --delete should delete quota project ID ========================================================== 03:57:25 (1768553845) [ 7332.286503] LustreError: 177766:0:(qsd_handler.c:337:qsd_req_completion()) $$$ DQACQ failed with -3, flags:0x1 qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:1032 req:1 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 7332.324484] LustreError: 177766:0:(qsd_handler.c:794:qsd_op_begin0()) $$$ ID isn't enforced on master, it probably due to a legeal race, if this message is showing up constantly, there could be some inconsistence between master & slave, and quota reintegration needs be re-triggered. qsd:lustre-OST0001 qtype:usr id:60000 enforced:1 granted: 0 pending:0 waiting:0 req:0 usage: 0 qunit:0 qtune:0 edquot:0 default:no revoke:0 truncated:0 [ 7385.103178] Lustre: DEBUG MARKER: == sanity-quota test 49a: lfs quota -a prints the quota usage for all quota IDs ========================================================== 03:58:32 (1768553912) [ 7391.692531] Lustre: *** cfs_fail_loc=a09, val=0*** [ 7391.700543] Lustre: Skipped 1 previous similar message [ 7393.740964] Lustre: *** cfs_fail_loc=a09, val=0*** [ 7393.743959] Lustre: Skipped 77 previous similar messages [ 7397.779648] Lustre: *** cfs_fail_loc=a09, val=0*** [ 7397.785221] Lustre: Skipped 157 previous similar messages [ 7405.785113] Lustre: *** cfs_fail_loc=a09, val=0*** [ 7405.791133] Lustre: Skipped 311 previous similar messages [ 7421.835677] Lustre: *** cfs_fail_loc=a09, val=0*** [ 7421.837288] Lustre: Skipped 789 previous similar messages [ 7453.877270] Lustre: *** cfs_fail_loc=a09, val=0*** [ 7453.880903] Lustre: Skipped 1441 previous similar messages [ 7517.919752] Lustre: *** cfs_fail_loc=a09, val=0*** [ 7517.924138] Lustre: Skipped 3111 previous similar messages [ 7839.075945] Lustre: *** cfs_fail_loc=a08, val=0*** [ 7839.077571] Lustre: Skipped 2107 previous similar messages [ 7839.099826] Lustre: *** cfs_fail_loc=a08, val=0*** [ 7839.119576] Lustre: Skipped 7 previous similar messages [ 7906.284430] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 7906.300231] 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 [ 7906.327433] Lustre: Skipped 5 previous similar messages [ 7906.351588] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7906.355986] Lustre: Skipped 1 previous similar message [ 7911.906253] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7911.936163] Lustre: Skipped 6 previous similar messages [ 7912.747246] LustreError: 191382:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 7912.759026] LustreError: 191382:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 7912.999241] Lustre: server umount lustre-MDT0000 complete [ 7916.830016] LustreError: 183469:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768554446 with bad export cookie 7571255308009486743 [ 7916.834258] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7916.838043] LustreError: 183469:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 7917.026501] LustreError: 179714:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7917.026877] 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 [ 7917.031153] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 7917.045766] LustreError: 179714:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 7917.062261] Lustre: Skipped 4 previous similar messages [ 7921.061348] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 7921.066984] Lustre: Skipped 1 previous similar message [ 7926.240555] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 7931.359977] Lustre: lustre-MDT0001 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 7931.458503] LustreError: 191588:0:(obd_class.h:479:obd_check_dev()) Device 18 not setup [ 7931.465819] LustreError: 191588:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 7931.594174] Lustre: server umount lustre-MDT0001 complete [ 7935.772248] LustreError: 191792:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 7935.782064] LustreError: 191792:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 7935.965185] Lustre: server umount lustre-OST0000 complete [ 7940.448658] LustreError: 191992:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 7940.461142] LustreError: 191992:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 7940.707748] Lustre: server umount lustre-OST0001 complete [ 7948.353565] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_hostid [ 7956.984591] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 8012.554440] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 8024.700730] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8024.963125] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 8024.991568] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 8025.077326] Lustre: lustre-MDT0000: new disk, initializing [ 8025.222366] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8025.245061] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 8030.316561] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8041.392337] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8041.525510] Lustre: 194865:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 8041.586376] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 8041.589426] Lustre: Skipped 1 previous similar message [ 8041.658710] Lustre: lustre-MDT0001: new disk, initializing [ 8041.734869] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 8041.768647] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 8041.781380] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 8046.672557] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8051.954690] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 8059.850524] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8060.082134] Lustre: lustre-OST0000: new disk, initializing [ 8060.089196] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 8060.192497] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 8061.952862] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 8061.968982] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 8062.093545] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 8067.567991] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8080.291321] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8080.431665] Lustre: lustre-OST0001: new disk, initializing [ 8080.434141] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 8080.492839] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 8082.353930] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 8082.367889] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 8082.454507] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 8088.131621] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8098.993518] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8103.706133] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 8134.381745] Lustre: DEBUG MARKER: == sanity-quota test 49b: lfs quota -a --blocks has a delimiter ========================================================== 04:11:02 (1768554662) [ 8141.522884] Lustre: DEBUG MARKER: == sanity-quota test 50: Test if lfs find --projid works ========================================================== 04:11:08 (1768554668) [ 8175.165656] Lustre: DEBUG MARKER: == sanity-quota test 51: Test project accounting with mv/cp ========================================================== 04:11:42 (1768554702) [ 8218.354086] Lustre: DEBUG MARKER: == sanity-quota test 52: Rename normal file across project ID ========================================================== 04:12:25 (1768554745) [ 8241.586817] Lustre: DEBUG MARKER: rename directory return 255 [ 8281.573349] Lustre: DEBUG MARKER: == sanity-quota test 53: Project inherit attribute could be cleared ========================================================== 04:13:28 (1768554808) [ 8304.475060] Lustre: DEBUG MARKER: == sanity-quota test 54: basic lfs project interface test ========================================================== 04:13:51 (1768554831) [ 8344.308818] Lustre: DEBUG MARKER: == sanity-quota test 55: Chgrp should be affected by group quota ========================================================== 04:14:31 (1768554871) [ 8475.629675] Lustre: DEBUG MARKER: == sanity-quota test 56: lfs quota -t should work well === 04:16:42 (1768555002) [ 8505.139958] Lustre: DEBUG MARKER: == sanity-quota test 57: lfs project could tolerate errors ========================================================== 04:17:12 (1768555032) [ 8539.437822] Lustre: DEBUG MARKER: == sanity-quota test 58: project ID should be kept for new mirrors created by FID ========================================================== 04:17:46 (1768555066) [ 8663.178139] Lustre: DEBUG MARKER: == sanity-quota test 59: lfs project dosen't crash kernel with project disabled ========================================================== 04:19:50 (1768555190) [ 8666.592706] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 8666.597049] 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 [ 8666.605434] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8666.608792] Lustre: Skipped 3 previous similar messages [ 8669.154388] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8669.157516] 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 [ 8672.326275] LustreError: 210574:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 8672.333098] LustreError: 210574:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 8672.630209] Lustre: server umount lustre-MDT0000 complete [ 8674.277561] LustreError: 195733:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8674.308217] LustreError: 195733:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 8676.494623] LustreError: 194858:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768555206 with bad export cookie 7571255308009858926 [ 8676.498756] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8676.516343] LustreError: 194858:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 8676.604882] LustreError: 210776:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 8676.610179] LustreError: 210776:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 8676.818476] Lustre: server umount lustre-MDT0001 complete [ 8689.588610] LustreError: 210977:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 8689.598138] LustreError: 210977:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 8689.786272] Lustre: server umount lustre-OST0000 complete [ 8704.260993] LustreError: 211179:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 8704.266285] LustreError: 211179:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 8704.540026] Lustre: server umount lustre-OST0001 complete [ 8725.809925] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 8737.253331] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8737.542853] LustreError: 212553:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8737.598183] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8737.614978] 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 [ 8741.792174] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8742.879960] LustreError: 212553:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8750.857226] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8751.218389] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 8751.239830] 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 [ 8756.091157] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8759.300350] Lustre: 213663:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 8766.777226] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8767.249105] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 8767.257170] 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 [ 8775.074163] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8776.494639] LustreError: 214018:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8776.518774] LustreError: 214018:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 8782.852557] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:20 to 0x280000401:65) [ 8784.573257] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8784.961121] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 8784.974053] 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 [ 8786.270877] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:65) [ 8791.859723] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8800.299755] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8804.450361] Lustre: 215507:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 8817.019111] LustreError: 215524:0:(osd_handler.c:3458:osd_quota_transfer()) lustre-MDT0000: quota transfer failed. Is project enforcement enabled on the ldiskfs filesystem? rc = -95 [ 8822.752121] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 8822.764044] 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 [ 8822.779425] Lustre: Skipped 2 previous similar messages [ 8822.790041] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8822.800743] Lustre: Skipped 3 previous similar messages [ 8827.143530] LustreError: 215901:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 8827.159401] LustreError: 215901:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 8827.331750] Lustre: server umount lustre-MDT0000 complete [ 8830.953384] LustreError: 215906:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8830.982908] LustreError: 215906:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 8831.482233] LustreError: 215902:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768555361 with bad export cookie 7571255308009907856 [ 8831.492059] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8831.495047] LustreError: 215902:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 8831.855305] Lustre: server umount lustre-MDT0001 complete [ 8846.984412] LustreError: 216307:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 8847.002886] LustreError: 216307:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 8847.198732] Lustre: server umount lustre-OST0000 complete [ 8862.006942] Lustre: server umount lustre-OST0001 complete [ 8883.843206] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [ 8895.683228] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8896.143760] LustreError: 217884:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8896.250134] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 8901.247805] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8911.544451] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8917.190597] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8920.604156] Lustre: 218997:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 8928.634209] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8936.087093] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8941.305179] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:67 to 0x280000401:97) [ 8948.317662] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8950.857483] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:20 to 0x2c0000401:97) [ 8958.064466] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8968.547621] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8973.571482] Lustre: 220849:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 9002.887300] Lustre: DEBUG MARKER: == sanity-quota test 60: Test quota for root with setgid ========================================================== 04:25:30 (1768555530) [ 9053.745508] Lustre: DEBUG MARKER: SKIP: sanity-quota test_61 skipping SLOW test 61 [ 9055.630665] Lustre: DEBUG MARKER: == sanity-quota test 62: Project inherit should be only changed by root ========================================================== 04:26:23 (1768555583) [ 9077.738271] Lustre: DEBUG MARKER: SKIP: sanity-quota test_63 skipping excluded test 63 [ 9080.044627] Lustre: DEBUG MARKER: == sanity-quota test 64: lfs project on non-dir/files should succeed ========================================================== 04:26:47 (1768555607) [ 9117.900313] Lustre: DEBUG MARKER: SKIP: sanity-quota test_65 skipping excluded test 65 [ 9119.950509] Lustre: DEBUG MARKER: == sanity-quota test 66: nonroot user can not change project state in default ========================================================== 04:27:27 (1768555647) [ 9153.013649] Lustre: DEBUG MARKER: == sanity-quota test 67: quota pools recalculation ======= 04:28:00 (1768555680) [ 9166.164253] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [ 9171.582710] Lustre: 226883:0:(qsd_reint.c:241:qsd_reint_index()) lustre-OST0000: index version for fid [0x200000005:0x1007:0x0] is 0, but index isn't empty (1) [ 9171.623947] Lustre: 226883:0:(qsd_reint.c:241:qsd_reint_index()) Skipped 1 previous similar message [ 9176.220962] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0000.recovery_status 1475 [ 9182.155931] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing _wait_recovery_complete *.lustre-OST0001.recovery_status 1475 [ 9185.672024] Lustre: DEBUG MARKER: Write... [ 9203.391176] LustreError: 228098:0:(mgs_handler.c:1102:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [ 9209.095549] Lustre: DEBUG MARKER: Write... [ 9220.657870] Lustre: DEBUG MARKER: Write... [ 9292.294724] Lustre: DEBUG MARKER: == sanity-quota test 68: slave number in quota pool changed after each add/remove OST ========================================================== 04:30:19 (1768555819) [ 9320.548785] LustreError: 231872:0:(mgs_handler.c:1102:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.qpool1 [ 9367.704648] Lustre: DEBUG MARKER: == sanity-quota test 69: EDQUOT at one of pools shouldn't affect DOM ========================================================== 04:31:35 (1768555895) [ 9399.393453] Lustre: DEBUG MARKER: User quota (block hardlimit:200 MB) [ 9401.052092] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 9484.412313] Lustre: DEBUG MARKER: == sanity-quota test 70a: check lfs setquota/quota with a pool option ========================================================== 04:33:31 (1768556011) [ 9529.352618] Lustre: DEBUG MARKER: == sanity-quota test 70b: lfs setquota pool works properly ========================================================== 04:34:16 (1768556056) [ 9564.830376] Lustre: DEBUG MARKER: == sanity-quota test 71a: Check PFL with quota pools ===== 04:34:52 (1768556092) [ 9576.807366] Lustre: DEBUG MARKER: User quota (block hardlimit:100 MB) [ 9598.403827] Lustre: DEBUG MARKER: Write... [ 9600.679051] Lustre: DEBUG MARKER: Write out of block quota ... [ 9679.884679] Lustre: DEBUG MARKER: == sanity-quota test 71b: Check SEL with quota pools ===== 04:36:47 (1768556207) [ 9691.281472] Lustre: DEBUG MARKER: User quota (block hardlimit:1000 MB) [ 9716.677172] LustreError: 221901:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool2 id:60000 enforced:1 hard:10240 soft:0 granted:10240 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 9773.823652] Lustre: DEBUG MARKER: == sanity-quota test 72: lfs quota --pool prints only pool's OSTs ========================================================== 04:38:21 (1768556301) [ 9785.453895] Lustre: DEBUG MARKER: User quota (block hardlimit:50 MB) [ 9802.218314] Lustre: DEBUG MARKER: Write... [ 9804.687518] Lustre: DEBUG MARKER: Write out of block quota ... [ 9851.790457] Lustre: DEBUG MARKER: == sanity-quota test 73a: default limits at OST Pool Quotas ========================================================== 04:39:39 (1768556379) [ 9880.177047] Lustre: DEBUG MARKER: set to use default quota [ 9881.199931] Lustre: DEBUG MARKER: set default quota [ 9882.578094] Lustre: DEBUG MARKER: get default quota [ 9888.038665] Lustre: DEBUG MARKER: Test not out of quota [ 9891.556563] Lustre: DEBUG MARKER: Test out of quota [ 9900.847548] Lustre: DEBUG MARKER: Increase default quota [ 9918.017562] Lustre: DEBUG MARKER: Set quota to override default quota [ 9918.067613] LustreError: 217880:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:20480 soft:20480 granted:45056 time:1769161247 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [ 9927.282552] Lustre: DEBUG MARKER: Set to use default quota again [ 9941.962465] Lustre: DEBUG MARKER: Cleanup [ 9994.390462] Lustre: DEBUG MARKER: == sanity-quota test 73b: default OST Pool Quotas limit for new user ========================================================== 04:42:02 (1768556522) [10016.964749] Lustre: DEBUG MARKER: set default quota for qpool1 [10018.798430] Lustre: DEBUG MARKER: Write from user that hasn't lqe [10058.307810] Lustre: DEBUG MARKER: == sanity-quota test 74: check quota pools per user ====== 04:43:05 (1768556585) [10131.912648] Lustre: DEBUG MARKER: == sanity-quota test 75: nodemap squashed root respects quota enforcement ========================================================== 04:44:19 (1768556659) [10190.614139] Lustre: DEBUG MARKER: Write... [10194.005681] Lustre: DEBUG MARKER: Write out of block quota ... [10291.252447] Lustre: DEBUG MARKER: == sanity-quota test 76: project ID 4294967295 should be not allowed ========================================================== 04:46:58 (1768556818) [10321.077651] Lustre: DEBUG MARKER: == sanity-quota test 77: lfs setquota should fail in Lustre mount with 'ro' ========================================================== 04:47:28 (1768556848) [10329.298268] Lustre: DEBUG MARKER: == sanity-quota test 78A: Check fallocate increase quota usage ========================================================== 04:47:36 (1768556856) [10369.207273] Lustre: DEBUG MARKER: == sanity-quota test 78a: Check fallocate increase projectid usage ========================================================== 04:48:16 (1768556896) [10407.228705] Lustre: DEBUG MARKER: == sanity-quota test 79: access to non-existed dt-pool/info doesn't cause a panic ========================================================== 04:48:54 (1768556934) [10430.956425] Lustre: DEBUG MARKER: == sanity-quota test 80: check for EDQUOT after OST failover ========================================================== 04:49:18 (1768556958) [10458.252803] Lustre: *** cfs_fail_loc=a06, val=0*** [10458.255427] Lustre: Skipped 1 previous similar message [10458.567648] LustreError: 217897:0:(qmt_lock.c:446:qmt_lvbo_update()) $$$ failed to release quota space on glimpse 0!=2048 : rc = -11 [10458.567648] qmt:lustre-QMT0000 pool:dt-0x0 id:60000 enforced:1 hard:102400 soft:0 granted:23552 time:0 qunit: 16384 edquot:0 may_rel:0 revoke:0 default:no [10464.628808] Lustre: Failing over lustre-OST0001 [10464.671119] LustreError: 265201:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [10464.673583] LustreError: 265201:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [10464.722454] Lustre: server umount lustre-OST0001 complete [10464.741107] LustreError: lustre-OST0001-osc-MDT0000: operation ost_destroy to node 0@lo failed: rc = -107 [10464.754223] 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 [10464.768868] Lustre: Skipped 3 previous similar messages [10464.776372] LustreError: 219352:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [10464.799656] LustreError: 219352:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [10466.275379] LustreError: lustre-OST0001-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [10466.305220] Lustre: lustre-OST0001-osc-MDT0001: Connection to lustre-OST0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [10474.465510] LustreError: 219349:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-OST0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [10474.509992] LustreError: 219349:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [10475.636396] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [10476.113733] Lustre: lustre-OST0001: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [10476.163345] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [10477.287755] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [10478.014250] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [10478.014522] Lustre: lustre-OST0001-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [10478.014531] Lustre: Skipped 8 previous similar messages [10483.590995] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10528.378544] Lustre: DEBUG MARKER: == sanity-quota test 81: Race qmt_start_pool_recalc with qmt_pool_free ========================================================== 04:50:55 (1768557055) [10538.801515] Lustre: DEBUG MARKER: User quota (block hardlimit:20 MB) [10546.532142] LustreError: 268004:0:(qmt_pool.c:1295:qmt_pool_recalc()) cfs_fail_timeout id a07 sleeping for 10000ms [10546.539993] LustreError: 268004:0:(qmt_pool.c:1295:qmt_pool_recalc()) Skipped 5 previous similar messages [10550.240192] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [10550.261074] 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 [10550.274484] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [10550.285168] Lustre: Skipped 4 previous similar messages [10552.186301] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.42@tcp (stopping) [10556.543233] LustreError: 268004:0:(qmt_pool.c:1295:qmt_pool_recalc()) cfs_fail_timeout id a07 awake [10556.643283] LustreError: 268153:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [10556.650973] LustreError: 268153:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [10556.911645] Lustre: server umount lustre-MDT0000 complete [10557.288750] LustreError: 217880:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.203.42@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [10557.305819] LustreError: 217880:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [10565.497777] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [10565.612545] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [10566.026752] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [10566.028468] Lustre: Skipped 3 previous similar messages [10566.075165] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:129) [10566.089145] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:112 to 0x280000401:129) [10571.067428] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [10571.249750] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [10571.254807] Lustre: Skipped 1 previous similar message [10602.625092] Lustre: DEBUG MARKER: == sanity-quota test 82: verify more than 8 qids for single operation ========================================================== 04:52:10 (1768557130) [10624.381540] Lustre: DEBUG MARKER: == sanity-quota test 83: Setting default quota shouldn't affect grace time ========================================================== 04:52:31 (1768557151) [10645.401516] Lustre: DEBUG MARKER: == sanity-quota test 84: Reset quota should fix the insane granted quota ========================================================== 04:52:52 (1768557172) [10687.704774] Lustre: *** cfs_fail_loc=a08, val=0*** [10687.727836] Lustre: Skipped 8 previous similar messages [10687.754113] Lustre: *** cfs_fail_loc=a08, val=0*** [10687.760022] Lustre: Skipped 7 previous similar messages [10771.777529] Lustre: DEBUG MARKER: == sanity-quota test 85: do not hung at write with the least_qunit ========================================================== 04:54:58 (1768557298) [10801.433399] LustreError: 221903:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:dt-qpool1 id:60000 enforced:1 hard:3072 soft:0 granted:3072 time:0 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [10852.042716] Lustre: DEBUG MARKER: == sanity-quota test 86: Pre-acquired quota should be released if quota is over limit ========================================================== 04:56:18 (1768557378) [10915.978164] LustreError: 217878:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1769162245 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11056.641133] LustreError: 217878:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:60000 enforced:1 hard:2048 soft:2048 granted:16384 time:1769162386 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11196.885724] LustreError: 225383:0:(qmt_entry.c:552:qmt_adjust_edquot()) $$$ set revoke_time explicitly qmt:lustre-QMT0000 pool:md-0x0 id:1000 enforced:1 hard:2048 soft:2048 granted:16384 time:1769162526 qunit: 1024 edquot:0 may_rel:0 revoke:0 default:no [11304.678149] Lustre: DEBUG MARKER: == sanity-quota test 87: lfs quota -a should print default quota setting ========================================================== 05:03:52 (1768557832) [11311.372045] Lustre: *** cfs_fail_loc=a09, val=0*** [11311.379613] Lustre: Skipped 1 previous similar message [11369.955503] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [11369.959876] 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 [11369.969518] Lustre: Skipped 3 previous similar messages [11369.974976] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [11369.984429] Lustre: Skipped 4 previous similar messages [11370.980256] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [11370.984068] 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 [11370.989093] Lustre: Skipped 1 previous similar message [11371.012699] Lustre: Skipped 1 previous similar message [11375.419219] LustreError: 278418:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [11375.427933] LustreError: 278418:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [11375.623981] Lustre: server umount lustre-MDT0000 complete [11376.106318] LustreError: 277201:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [11376.139243] LustreError: 277201:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 12 previous similar messages [11381.216504] LustreError: 277010:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [11381.246669] LustreError: 277010:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [11384.249109] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [11384.393547] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [11384.775402] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [11384.845680] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:132 to 0x280000401:161) [11384.847304] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:113 to 0x2c0000401:161) [11389.543741] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11389.921752] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [11389.935603] Lustre: Skipped 2 previous similar messages [11389.964060] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [11403.979837] Lustre: DEBUG MARKER: == sanity-quota test 88: Writing over quota should not hang ========================================================== 05:05:31 (1768557931) [11405.356062] Lustre: DEBUG MARKER: SKIP: sanity-quota test_88 require client with >4k pages [11406.792532] Lustre: DEBUG MARKER: == sanity-quota test 89: Show default quota with squash_uid ========================================================== 05:05:34 (1768557934) [11429.626392] Lustre: DEBUG MARKER: == sanity-quota test 90a: lfs quota should work without mount point ========================================================== 05:05:57 (1768557957) [11464.196640] Lustre: DEBUG MARKER: == sanity-quota test 90b: lfs quota should work with multiple mount points ========================================================== 05:06:31 (1768557991) [11498.321869] Lustre: DEBUG MARKER: == sanity-quota test 91: new quota index files in quota_master ========================================================== 05:07:05 (1768558025) [11512.875931] 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 [11512.885677] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [11512.888563] Lustre: Skipped 2 previous similar messages [11512.889761] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [11512.889768] Lustre: Skipped 3 previous similar messages [11517.933983] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [11517.942820] Lustre: Skipped 6 previous similar messages [11519.163606] LustreError: 282819:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [11519.171855] LustreError: 282819:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [11519.313381] Lustre: server umount lustre-MDT0000 complete [11523.046934] LustreError: 219361:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [11523.066102] LustreError: 219361:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [11523.141409] LustreError: 217864:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768558052 with bad export cookie 7571255308011012295 [11523.152955] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [11523.162544] LustreError: 217864:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [11528.167737] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [11528.199418] Lustre: Skipped 2 previous similar messages [11528.216038] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [11528.230883] Lustre: Skipped 1 previous similar message [11529.404862] LustreError: 283021:0:(obd_class.h:479:obd_check_dev()) Device 18 not setup [11529.413394] LustreError: 283021:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [11529.577769] Lustre: server umount lustre-MDT0001 complete [11533.485109] LustreError: 283223:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [11533.497332] LustreError: 283223:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [11533.624267] Lustre: server umount lustre-OST0000 complete [11537.234726] Lustre: server umount lustre-OST0001 complete [11543.869991] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_hostid [11552.063383] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [11594.106907] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [11594.432366] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [11594.463370] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [11594.532863] Lustre: lustre-MDT0000: new disk, initializing [11594.602615] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [11594.619129] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [11599.439025] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11605.700488] Lustre: DEBUG MARKER: oleg342-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [11613.973117] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [11614.164899] Lustre: lustre-OST0000: new disk, initializing [11614.171831] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [11614.178368] Lustre: Skipped 1 previous similar message [11614.214326] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [11615.288298] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [11615.296227] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [11615.328275] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [11621.564811] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11628.833567] Lustre: DEBUG MARKER: oleg342-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [11636.716233] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [11636.876495] Lustre: lustre-OST0001: new disk, initializing [11636.880253] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [11636.924526] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [11638.969074] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [11638.974823] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [11638.997113] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [11643.764413] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11651.291094] Lustre: DEBUG MARKER: oleg342-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0001-osc-[-0-9a-f]*.ost_server_uuid [11662.237411] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.42@tcp (stopping) [11664.871388] 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 [11664.882136] Lustre: Skipped 1 previous similar message [11667.950715] LustreError: 288372:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [11667.956565] LustreError: 288372:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [11668.102965] Lustre: server umount lustre-MDT0000 complete [11678.784154] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [11678.877245] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [11679.226273] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [11683.688803] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11685.361965] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [11685.377429] Lustre: Skipped 3 previous similar messages [11689.330956] Lustre: DEBUG MARKER: oleg342-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [11694.319765] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 3 sec [11695.663065] LustreError: 288988:0:(qmt_entry.c:1166:qmt_map_lge_idx()) qmt: cannot map ostidx 1, num_used 1: rc = -22 [11698.696864] LustreError: 288987:0:(qmt_entry.c:1166:qmt_map_lge_idx()) qmt: cannot map ostidx 1, num_used 1: rc = -22 [11701.398270] LustreError: 289600:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [11701.405284] LustreError: 289600:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [11701.686191] Lustre: server umount lustre-MDT0000 complete [11708.618343] LustreError: 285588:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768558238 with bad export cookie 7571255308011015319 [11708.632052] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [11719.318404] Lustre: server umount lustre-OST0000 complete [11722.207218] Lustre: 3653:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768558235/real 1768558235] req@ffff97de84dd1c00 x1854455554339328/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768558251 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [11722.249031] 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 [11722.838492] Lustre: server umount lustre-OST0001 complete [11739.494613] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_hostid [11748.942963] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [11800.756719] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing load_modules_local [11810.975664] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [11811.290605] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [11811.332302] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [11811.417497] Lustre: lustre-MDT0000: new disk, initializing [11811.482580] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [11811.497809] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [11816.019416] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11827.032872] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [11827.088654] Lustre: 293634:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [11827.112479] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [11827.117128] Lustre: Skipped 1 previous similar message [11827.183804] Lustre: lustre-MDT0001: new disk, initializing [11827.284158] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [11827.295438] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [11831.646641] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11836.412938] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [11844.155354] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [11844.462450] Lustre: lustre-OST0000: new disk, initializing [11844.468568] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [11844.557385] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [11844.570800] Lustre: Skipped 1 previous similar message [11845.814270] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [11845.826976] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [11845.999132] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [11851.942446] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11863.781376] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [11863.949496] Lustre: lustre-OST0001: new disk, initializing [11863.954901] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [11865.114391] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [11865.124545] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [11865.186548] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [11870.527149] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [11880.641503] Lustre: DEBUG MARKER: Using TIMEOUT=20 [11884.214577] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [11896.777732] Lustre: DEBUG MARKER: == sanity-quota test 92: Cannot set inode limit with Quota Pools ========================================================== 05:13:44 (1768558424) [11914.511976] Lustre: DEBUG MARKER: == sanity-quota test 93: update projid while client write to OST ========================================================== 05:14:02 (1768558442) [11933.411803] Lustre: *** cfs_fail_loc=170c, val=0*** [11979.890689] Lustre: DEBUG MARKER: == sanity-quota test 94: lfs quota all respects nodemap offset ========================================================== 05:15:06 (1768558506) [12016.607642] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [12016.615319] 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 [12016.637552] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [12016.645433] Lustre: Skipped 3 previous similar messages [12022.419873] LustreError: 300559:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [12022.433774] LustreError: 300559:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [12022.600507] Lustre: server umount lustre-MDT0000 complete [12023.784376] LustreError: 293642:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [12023.812257] LustreError: 293642:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [12031.826287] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [12031.945694] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [12032.257740] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [12032.264904] Lustre: Skipped 1 previous similar message [12032.322395] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:33) [12036.824222] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12037.620737] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [12037.632729] Lustre: Skipped 1 previous similar message [12037.654760] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [12047.848136] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [12049.778209] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.42@tcp (stopping) [12049.791048] Lustre: Skipped 10 previous similar messages [12050.807054] Lustre: server umount lustre-MDT0000 complete [12058.704398] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [12058.905240] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [12059.160463] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:65) [12063.349630] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [12064.230945] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [12070.335910] Lustre: DEBUG MARKER: == sanity-quota test 95a: Correct limits for squashed root ========================================================== 05:16:37 (1768558597) [12097.879749] Lustre: DEBUG MARKER: == sanity-quota test 95b: df respects squashed project id ========================================================== 05:17:04 (1768558624) [12133.984190] Lustre: DEBUG MARKER: == sanity-quota test 96: quota grant should be released when big files are deleted ========================================================== 05:17:41 (1768558661) [12135.791869] Lustre: DEBUG MARKER: SKIP: sanity-quota test_96 OST is too small, skip the test [12137.179683] Lustre: DEBUG MARKER: == sanity-quota test 97a: LQA control commands =========== 05:17:45 (1768558665) [12176.131155] Lustre: DEBUG MARKER: == sanity-quota test complete, duration 11978 sec ======== 05:18:23 (1768558703) [12178.471900] Lustre: DEBUG MARKER: === sanity-quota: start cleanup 05:18:25 (1768558705) === [12182.307441] Lustre: DEBUG MARKER: === sanity-quota: finish cleanup 05:18:29 (1768558709) === [12192.224834] 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 [12192.225924] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [12192.239182] Lustre: Skipped 9 previous similar messages [12192.239343] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [12192.276704] Lustre: Skipped 3 previous similar messages [12193.366849] LustreError: 306709:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [12193.378981] LustreError: 306709:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [12193.553434] Lustre: server umount lustre-MDT0000 complete [12197.345563] LustreError: 293647:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [12197.358650] LustreError: 293647:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 18 previous similar messages [12202.334209] LustreError: 293628:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768558731 with bad export cookie 7571255308011019155 [12202.341821] LustreError: MGC192.168.203.142@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [12202.355135] LustreError: 293628:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [12202.604340] Lustre: server umount lustre-MDT0001 complete [12211.083188] Lustre: server umount lustre-OST0000 complete [12219.428879] Lustre: server umount lustre-OST0001 complete [12235.321956] Lustre: DEBUG MARKER: oleg342-server.virtnet: executing unload_modules_local [12238.517558] Key type lgssc unregistered [12238.843223] LNet: 308891:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [12238.864505] LNetError: 308891:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [12238.881499] LNet: Removed LNI 192.168.203.142@tcp [12240.061145] Key type .llcrypt unregistered [12240.065568] Key type ._llcrypt unregistered