[ 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 488521573 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 2640MB 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.001010] APIC: Switch to symmetric I/O mode setup [ 0.002342] x2apic enabled [ 0.003007] Switched APIC routing to physical x2apic. [ 0.004014] kvm-guest: setup PV IPIs [ 0.007000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007011] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008025] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009015] pid_max: default: 32768 minimum: 301 [ 0.011129] LSM: Security Framework initializing [ 0.012057] Yama: becoming mindful. [ 0.013039] SELinux: Initializing. [ 0.014075] *** VALIDATE selinux *** [ 0.022747] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027229] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028159] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030105] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031127] *** VALIDATE tmpfs *** [ 0.033028] *** VALIDATE proc *** [ 0.034113] *** VALIDATE cgroup *** [ 0.035013] *** VALIDATE cgroup2 *** [ 0.037249] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038145] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039012] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040029] Spectre V2 : User space: Vulnerable [ 0.042006] Speculative Store Bypass: Vulnerable [ 0.045165] debug: unmapping init [mem 0xffffffffb6059000-0xffffffffb6060fff] [ 0.047239] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.048654] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.049025] ... version: 2 [ 0.050013] ... bit width: 48 [ 0.051011] ... generic registers: 4 [ 0.052013] ... value mask: 0000ffffffffffff [ 0.053014] ... max period: 00007fffffffffff [ 0.054013] ... fixed-purpose events: 3 [ 0.055010] ... event mask: 000000070000000f [ 0.056304] rcu: Hierarchical SRCU implementation. [ 0.058377] smp: Bringing up secondary CPUs ... [ 0.059550] x86: Booting SMP configuration: [ 0.060024] .... node #0, CPUs: #1 #2 #3 [ 0.066080] smp: Brought up 1 node, 4 CPUs [ 0.068016] smpboot: Max logical packages: 1 [ 0.069056] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.147572] node 0 deferred pages initialised in 76ms [ 0.149623] devtmpfs: initialized [ 0.150151] x86/mm: Memory block size: 128MB [ 0.152291] gcov: version magic: 0x41383552 [ 0.153535] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.154087] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.155244] pinctrl core: initialized pinctrl subsystem [ 0.156190] [ 0.157014] ************************************************************* [ 0.158018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.159014] ** ** [ 0.160143] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.161016] ** ** [ 0.162014] ** This means that this kernel is built to expose internal ** [ 0.163014] ** IOMMU data structures, which may compromise security on ** [ 0.164016] ** your system. ** [ 0.165016] ** ** [ 0.166016] ** If you see this message and you are not debugging the ** [ 0.167014] ** kernel, report this immediately to your vendor! ** [ 0.168020] ** ** [ 0.169016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.170016] ************************************************************* [ 0.171613] NET: Registered protocol family 16 [ 0.172435] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.173048] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.174039] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.176014] cpuidle: using governor menu [ 0.177887] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.180395] PCI: Using configuration type 1 for base access [ 0.182130] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.194134] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.195021] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.198047] cryptd: max_cpu_qlen set to 1000 [ 0.201320] ACPI: Added _OSI(Module Device) [ 0.202016] ACPI: Added _OSI(Processor Device) [ 0.203019] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.204015] ACPI: Added _OSI(Processor Aggregator Device) [ 0.208088] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.210685] ACPI: Interpreter enabled [ 0.211065] ACPI: PM: (supports S0 S3 S4 S5) [ 0.212015] ACPI: Using IOAPIC for interrupt routing [ 0.214119] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.219352] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.228365] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.230070] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.234025] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.238119] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.243352] acpiphp: Slot [2] registered [ 0.244207] acpiphp: Slot [5] registered [ 0.246115] acpiphp: Slot [6] registered [ 0.247141] acpiphp: Slot [7] registered [ 0.249100] acpiphp: Slot [8] registered [ 0.250083] acpiphp: Slot [9] registered [ 0.251083] acpiphp: Slot [10] registered [ 0.252189] acpiphp: Slot [3] registered [ 0.254114] acpiphp: Slot [4] registered [ 0.255136] acpiphp: Slot [11] registered [ 0.257110] acpiphp: Slot [12] registered [ 0.258096] acpiphp: Slot [13] registered [ 0.260113] acpiphp: Slot [14] registered [ 0.262122] acpiphp: Slot [15] registered [ 0.264085] acpiphp: Slot [16] registered [ 0.265104] acpiphp: Slot [17] registered [ 0.267116] acpiphp: Slot [18] registered [ 0.268406] acpiphp: Slot [19] registered [ 0.270116] acpiphp: Slot [20] registered [ 0.272093] acpiphp: Slot [21] registered [ 0.274116] acpiphp: Slot [22] registered [ 0.276117] acpiphp: Slot [23] registered [ 0.277114] acpiphp: Slot [24] registered [ 0.279126] acpiphp: Slot [25] registered [ 0.280105] acpiphp: Slot [26] registered [ 0.282110] acpiphp: Slot [27] registered [ 0.283102] acpiphp: Slot [28] registered [ 0.285108] acpiphp: Slot [29] registered [ 0.287112] acpiphp: Slot [30] registered [ 0.288087] acpiphp: Slot [31] registered [ 0.289051] PCI host bridge to bus 0000:00 [ 0.290020] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.292019] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.294019] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.296025] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.299032] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.302027] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.304288] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.308249] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.311306] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.323017] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.328057] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.331224] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.333019] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.336020] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.338501] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.341963] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.345049] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.348848] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.354015] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.367882] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.374015] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.379272] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.388014] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.396020] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.420014] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.429474] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.435015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.443017] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.458015] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.467550] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.475016] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.483016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.496014] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.509924] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.514014] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.520016] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.537014] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.551237] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.555012] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.562020] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.592019] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.610169] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.617014] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.623019] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.635014] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.645585] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.647275] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.649242] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.652085] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.654235] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.659048] iommu: Default domain type: Passthrough [ 0.661475] SCSI subsystem initialized [ 0.662124] ACPI: bus type USB registered [ 0.664121] usbcore: registered new interface driver usbfs [ 0.667079] usbcore: registered new interface driver hub [ 0.669080] usbcore: registered new device driver usb [ 0.671186] pps_core: LinuxPPS API ver. 1 registered [ 0.673012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.676056] PTP clock support registered [ 0.678140] EDAC MC: Ver: 3.0.0 [ 0.681129] PCI: Using ACPI for IRQ routing [ 0.682769] NetLabel: Initializing [ 0.684012] NetLabel: domain hash size = 128 [ 0.686011] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.688086] NetLabel: unlabeled traffic allowed by default [ 0.690369] vgaarb: loaded [ 0.691486] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.693017] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.702158] clocksource: Switched to clocksource kvm-clock [ 0.810428] VFS: Disk quotas dquot_6.6.0 [ 0.812090] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.814577] *** VALIDATE ramfs *** [ 0.815710] *** VALIDATE hugetlbfs *** [ 0.817128] pnp: PnP ACPI init [ 0.819466] pnp: PnP ACPI: found 6 devices [ 0.834969] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.837522] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.839100] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.840922] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.843317] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.845445] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.847484] NET: Registered protocol family 2 [ 0.849757] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.853889] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.857131] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.863139] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.865689] TCP: Hash tables configured (established 65536 bind 65536) [ 0.868171] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.871537] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.874399] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.876721] NET: Registered protocol family 1 [ 0.879208] RPC: Registered named UNIX socket transport module. [ 0.881362] RPC: Registered udp transport module. [ 0.882286] RPC: Registered tcp transport module. [ 0.883304] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.884864] NET: Registered protocol family 44 [ 0.886532] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.888381] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.889706] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.891645] PCI: CLS 0 bytes, default 64 [ 0.892962] Unpacking initramfs... [ 2.285558] debug: unmapping init [mem 0xffff9eb93cc54000-0xffff9eb93ffbffff] [ 2.289065] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.291127] software IO TLB: mapped [mem 0x00000000a1000000-0x00000000a5000000] (64MB) [ 2.293890] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.820898] Initialise system trusted keyrings [ 2.822806] Key type blacklist registered [ 2.824355] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.833580] zbud: loaded [ 2.836589] *** VALIDATE nfs *** [ 2.838049] *** VALIDATE nfs4 *** [ 2.839914] pstore: using deflate compression [ 2.842437] Platform Keyring initialized [ 2.938847] NET: Registered protocol family 38 [ 2.940728] Key type asymmetric registered [ 2.942272] Asymmetric key parser 'x509' registered [ 2.944154] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.947172] io scheduler mq-deadline registered [ 2.949101] io scheduler kyber registered [ 2.950752] io scheduler bfq registered [ 2.952379] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.953829] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.956118] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.958883] ACPI: Power Button [PWRF] [ 2.964243] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.972939] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.004647] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.013270] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.031431] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.061875] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.091910] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.097093] Non-volatile memory driver v1.3 [ 3.098287] Linux agpgart interface v0.103 [ 3.128840] virtio_blk virtio1: [vda] 134032 512-byte logical blocks (68.6 MB/65.4 MiB) [ 3.131813] vda: detected capacity change from 0 to 68624384 [ 3.147183] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.150470] vdb: detected capacity change from 0 to 1073741824 [ 3.173471] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.176882] vdc: detected capacity change from 0 to 2621440000 [ 3.194082] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.197353] vdd: detected capacity change from 0 to 2621440000 [ 3.211420] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.214487] vde: detected capacity change from 0 to 4294967296 [ 3.235912] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.239511] vdf: detected capacity change from 0 to 4294967296 [ 3.250457] libphy: Fixed MDIO Bus: probed [ 3.266747] usbcore: registered new interface driver usbserial_generic [ 3.269343] usbserial: USB Serial support registered for generic [ 3.271671] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.275822] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.277701] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.279647] mousedev: PS/2 mouse device common for all mice [ 3.283483] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.287434] rtc_cmos 00:05: RTC can wake from S4 [ 3.292573] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.293084] rtc_cmos 00:05: registered as rtc0 [ 3.299176] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.299361] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.301874] intel_pstate: CPU model not supported [ 3.308035] hid: raw HID events driver (C) Jiri Kosina [ 3.310358] usbcore: registered new interface driver usbhid [ 3.312630] usbhid: USB HID core driver [ 3.314428] drop_monitor: Initializing network drop monitor service [ 3.317093] Initializing XFRM netlink socket [ 3.319518] NET: Registered protocol family 10 [ 3.323628] Segment Routing with IPv6 [ 3.325250] NET: Registered protocol family 17 [ 3.327807] mpls_gso: MPLS GSO support [ 3.334246] RAS: Correctable Errors collector initialized. [ 3.337096] AVX version of gcm_enc/dec engaged. [ 3.340296] AES CTR mode by8 optimization enabled [ 3.413230] sched_clock: Marking stable (3413197084, 0)->(4334383518, -921186434) [ 3.416294] registered taskstats version 1 [ 3.417847] Loading compiled-in X.509 certificates [ 3.420249] zswap: loaded using pool lzo/zbud [ 3.446529] Key type big_key registered [ 3.460245] Key type encrypted registered [ 3.461663] ima: No TPM chip found, activating TPM-bypass! [ 3.464168] ima: Allocated hash algorithm: sha1 [ 3.465593] ima: No architecture policies found [ 3.467783] evm: Initialising EVM extended attributes: [ 3.469259] evm: security.selinux [ 3.469861] evm: security.ima [ 3.471131] evm: security.capability [ 3.472395] evm: HMAC attrs: 0x1 [ 3.474853] rtc_cmos 00:05: setting system clock to 2026-01-22 10:48:02 UTC (1769078882) [ 3.482720] debug: unmapping init [mem 0xffffffffb7003000-0xffffffffb71fffff] [ 3.485967] debug: unmapping init [mem 0xffffffffb5d82000-0xffffffffb6058fff] [ 3.494187] Write protecting the kernel read-only data: 28672k [ 3.497575] debug: unmapping init [mem 0xffffffffb4403000-0xffffffffb45fffff] [ 3.499477] debug: unmapping init [mem 0xffffffffb4d14000-0xffffffffb4dfffff] [ 3.526168] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.531878] systemd[1]: Detected virtualization kvm. [ 3.534359] systemd[1]: Detected architecture x86-64. [ 3.536168] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.558609] systemd[1]: No hostname configured. [ 3.559908] systemd[1]: Set hostname to . [ 3.561526] random: systemd: uninitialized urandom read (16 bytes read) [ 3.563543] systemd[1]: Initializing machine ID from random generator. [ 3.706706] random: systemd: uninitialized urandom read (16 bytes read) [ 3.709293] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 3.713235] random: systemd: uninitialized urandom read (16 bytes read) [ 3.715691] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 3.719223] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. Starting Setup Virtual Console... [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Swap. [ OK ] Listening on udev Control Socket. Starting Apply Kernel Variables... [ OK ] Started Dispatch Password Requests to Console Directory Watch. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ 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 Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.397611] device-mapper: uevent: version 1.0.3 [ 4.399988] 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... [ 4.958478] random: fast init done [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.156083] virtio_net virtio0 ens2: renamed from eth0 [ 5.267318] scsi host0: ata_piix [ 5.283546] scsi host1: ata_piix [ 5.285052] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.287574] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.037439] dracut-initqueue[580]: RTNETLINK answers: File exists [ 9.977341] random: crng init done [ 9.978604] random: 7 urandom warning(s) missed due to ratelimiting 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... [ 10.529414] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Timers. [ 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 Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. Stopping udev Kernel Device Manager... [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Swap. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.752043] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.005561] SELinux: Disabled at runtime. [ 12.074797] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 12.085506] systemd[1]: Detected virtualization kvm. [ 12.088174] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.619113] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.622426] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.626450] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.630355] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.633524] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.642526] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.646366] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice system-getty.slice. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting Kernel Debug File System... [ OK ] Listening on Process Core Dump Socket. [ OK ] Reached target rpc_pipefs.target. Mounting Huge Pages File System... Starting Remount Root and Kernel File Systems... [ OK ] Listening on initctl Compatibility Named Pipe. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Stopped target Switch Root. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. Mounting POSIX Message Queue File System... [ OK ] Stopped target Initrd File Systems. Starting Apply Kernel Variables... Activating swap /dev/disk/by-label/SWAP... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Stopped target Initrd Root File System. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ 12.800505] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Reached target Paths. [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Apply Kernel Variables. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 13.095673] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Coldplug all Devices. [ OK ] Started udev Kernel Device Manager. [ 13.441712] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.509494] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.577330] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.593726] EDAC sbridge: Ver: 1.1.2 [ 15.251103] Key type dns_resolver registered [ 15.533691] NFS: Registering the id_resolver key type [ 15.535127] Key type id_resolver registered [ 15.536291] 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 RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ 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 Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg315-server login: [ 51.771733] libcfs: loading out-of-tree module taints kernel. [ 51.847775] Key type ._llcrypt registered [ 51.850634] Key type .llcrypt registered [ 51.953475] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_hostid [ 75.847761] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing load_modules_local [ 77.475538] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 77.494829] alg: No test for adler32 (adler32-zlib) [ 78.943652] Lustre: Lustre: Build Version: 2.17.50_3_gca5b8be [ 79.796284] LNet: Added LNI 192.168.203.115@tcp [8/256/0/180] [ 81.600155] Key type lgssc registered [ 83.804805] Lustre: Echo OBD driver; http://www.lustre.org/ [ 104.582111] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 106.530722] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 115.433735] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 122.884698] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 130.200422] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 145.569699] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing load_modules_local [ 158.987071] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 159.053601] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 159.074663] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 160.335452] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 160.362546] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 160.415574] Lustre: lustre-MDT0000: new disk, initializing [ 160.482032] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 160.498311] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 164.049164] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 176.757299] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 176.871280] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 177.005584] Lustre: 6519: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 [ 177.048749] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 177.053074] Lustre: Skipped 1 previous similar message [ 177.146785] Lustre: lustre-MDT0001: new disk, initializing [ 177.223522] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 177.255952] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 177.265510] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 181.876221] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 188.002379] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 190.205668] hrtimer: interrupt took 7656263 ns [ 202.993268] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 203.116288] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 203.355209] Lustre: lustre-OST0000: new disk, initializing [ 203.362834] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 203.442293] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 205.516932] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 205.524513] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 205.604569] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 210.992920] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 226.130824] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 226.218594] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 226.416263] Lustre: lustre-OST0001: new disk, initializing [ 226.420669] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 226.464149] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 232.510831] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 232.531873] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 232.621615] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 234.298925] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 250.716278] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 258.496513] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 269.691192] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing check_logdir /tmp/testlogs/ [ 276.498936] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing yml_node [ 280.786313] Lustre: DEBUG MARKER: Client: 2.17.50.3 [ 283.011979] Lustre: DEBUG MARKER: MDS: 2.17.50.3 [ 285.029869] Lustre: DEBUG MARKER: OSS: 2.17.50.3 [ 286.856418] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Thu Jan 22 05:52:44 EST 2026 [ 301.571964] Lustre: DEBUG MARKER: excepting tests: 110f 131b 59 36 [ 302.982052] Lustre: DEBUG MARKER: === replay-single: start setup 05:53:01 (1769079181) === [ 306.571356] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing check_config_client /mnt/lustre [ 326.639431] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 330.188613] Lustre: 13197:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 333.240659] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 338.483907] Lustre: DEBUG MARKER: === replay-single: finish setup 05:53:36 (1769079216) === [ 341.582364] Lustre: DEBUG MARKER: == replay-single test 100a: DNE: create striped dir, drop update rep from MDT1, fail MDT1 ========================================================== 05:53:39 (1769079219) [ 342.796302] Lustre: *** cfs_fail_loc=1701, val=2147483648*** [ 342.797893] LustreError: 6529:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff9eb882f84380 x1855013737580288/t4294967300(0) o1000->lustre-MDT0000-mdtlov_UUID@0@lo:227/0 lens 264/4320 e 0 to 0 dl 1769079232 ref 1 fl Interpret:/200/0 rc 0/0 job:'osp_up1-0.0' uid:0 gid:0 projid:4294967295 [ 344.412558] Lustre: Failing over lustre-MDT0001 [ 344.534880] LustreError: 13724:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 344.546764] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 344.553217] 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 [ 344.621559] Lustre: server umount lustre-MDT0001 complete [ 345.575503] 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 [ 345.600130] Lustre: Skipped 1 previous similar message [ 350.511931] LustreError: 6524:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.15@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 350.531448] LustreError: 6524:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 6 previous similar messages [ 355.641843] LustreError: 6526:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.15@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 355.661961] LustreError: 6526:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 358.369058] Lustre: 7816:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079221/real 1769079221] req@ffff9eb9861cc700 x1855013737580288/t0(0) o1000->lustre-MDT0001-osp-MDT0000@0@lo:24/4 lens 264/4320 e 0 to 1 dl 1769079237 ref 2 fl Rpc:XQr/200/ffffffff rc 0/-1 job:'osp_up1-0.0' uid:0 gid:0 projid:4294967295 [ 360.756119] LustreError: 13780:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.15@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 360.781068] LustreError: 13780:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 362.733319] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 362.979206] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 364.638454] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 367.130496] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 368.120960] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 368.161189] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 375.226328] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 377.053248] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 386.015933] Lustre: DEBUG MARKER: == replay-single test 100b: DNE: create striped dir, fail MDT0 ========================================================== 05:54:24 (1769079264) [ 387.027028] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 387.032165] LustreError: 13780:0:(ldlm_lib.c:3326:target_send_reply_msg()) @@@ dropping reply req@ffff9eb9b5ef1880 x1855013715494272/t4294967361(0) o36->ecee0c4e-a258-47c0-b6ca-f609d5a774a7@192.168.203.15@tcp:312/0 lens 560/536 e 0 to 0 dl 1769079317 ref 1 fl Interpret:/200/0 rc 0/0 job:'lfs.0' uid:0 gid:0 projid:4294967295 [ 388.364971] Lustre: Failing over lustre-MDT0000 [ 388.542717] LustreError: 14997:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 388.547676] LustreError: 14997:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 388.587270] 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 [ 388.588623] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 388.594518] LustreError: 6525: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. [ 388.594528] LustreError: 6525:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 388.663387] Lustre: server umount lustre-MDT0000 complete [ 393.698293] LustreError: 6524: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. [ 393.707305] LustreError: 6524:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 7 previous similar messages [ 403.939877] LustreError: 13780: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. [ 403.967172] LustreError: 13780:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 9 previous similar messages [ 406.575697] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 406.654215] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 406.853217] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 410.803605] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 410.934337] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 412.142482] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 412.152180] Lustre: Skipped 2 previous similar messages [ 412.189284] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 412.207629] Lustre: 13780:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9eb88300ca80 x1855013715494272/t4294967361(0) o36->ecee0c4e-a258-47c0-b6ca-f609d5a774a7@192.168.203.15@tcp:337/0 lens 560/2880 e 0 to 0 dl 1769079342 ref 1 fl Interpret:/202/0 rc 0/0 job:'lfs.0' uid:0 gid:0 projid:4294967295 [ 412.234674] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:6 to 0x2c0000401:33) [ 412.246340] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:6 to 0x280000401:33) [ 418.517256] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 420.128238] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 428.609140] Lustre: DEBUG MARKER: == replay-single test 100c: DNE: create striped dir, abort_recov_mdt mds2 ========================================================== 05:55:06 (1769079306) [ 435.543142] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 437.208806] Lustre: Failing over lustre-MDT0001 [ 437.319137] LustreError: 16626:0:(obd_class.h:479:obd_check_dev()) Device 21 not setup [ 437.329048] LustreError: 16626:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 437.448605] Lustre: server umount lustre-MDT0001 complete [ 437.730958] 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 [ 437.737886] LustreError: 6526: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. [ 437.740026] Lustre: Skipped 5 previous similar messages [ 437.742557] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 437.759384] LustreError: 6526:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 448.650722] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 448.656308] LDISKFS-fs (dm-1): recovery complete [ 448.668378] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 448.930791] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 448.954187] Lustre: lustre-MDT0001: Aborting MDT recovery [ 448.964904] LustreError: 17296:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0000-osp-MDT0001: get update log duration 0, retries 0, failed: rc = -108 [ 450.718820] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 453.035990] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 454.119077] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 454.124784] Lustre: Skipped 3 previous similar messages [ 454.164525] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 454.172741] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 454.189809] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 454.237741] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:46 to 0x2c0000400:65) [ 454.239134] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:46 to 0x280000400:65) [ 468.058697] Lustre: Failing over lustre-MDT0001 [ 468.184274] LustreError: 17871:0:(obd_class.h:479:obd_check_dev()) Device 21 not setup [ 468.188566] LustreError: 17871:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 468.330673] Lustre: server umount lustre-MDT0001 complete [ 469.473630] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 469.476343] 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 [ 469.485943] Lustre: Skipped 2 previous similar messages [ 472.407162] LustreError: 6524:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.15@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 472.423148] LustreError: 6524:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 11 previous similar messages [ 486.118839] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 486.333510] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 487.726427] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 490.105436] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 491.494883] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 491.509668] Lustre: Skipped 2 previous similar messages [ 491.540989] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 491.579469] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:70 to 0x2c0000400:97) [ 491.582198] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 497.856322] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 499.340921] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 507.935639] Lustre: DEBUG MARKER: == replay-single test 100d: DNE: cancel update logs upon recovery abort ========================================================== 05:56:25 (1769079385) [ 521.168720] Lustre: Failing over lustre-MDT0001 [ 521.325198] LustreError: 19243:0:(obd_class.h:479:obd_check_dev()) Device 21 not setup [ 521.331204] LustreError: 19243:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 521.433709] Lustre: server umount lustre-MDT0001 complete [ 522.217874] 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 [ 522.222241] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 522.227200] Lustre: Skipped 2 previous similar messages [ 529.333750] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 529.574504] Lustre: lustre-MDT0001: Aborting client recovery [ 529.577531] LustreError: 19691:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 529.579318] LustreError: 19715:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0000-osp-MDT0001: get update log duration 0, retries 0, failed: rc = -108 [ 529.585510] Lustre: 19716:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 529.589802] LustreError: 19715:0:(lod_dev.c:510:lod_sub_recovery_thread()) Skipped 1 previous similar message [ 529.597221] Lustre: 19716:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client ecee0c4e-a258-47c0-b6ca-f609d5a774a7@ [ 529.601796] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 529.608621] Lustre: lustre-MDT0001-osd: cancel update llog [0x2400013a0:0x3:0x0] [ 529.619861] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000bd1:0x3:0x0] [ 529.666031] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:70 to 0x2c0000400:129) [ 529.668239] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 533.099191] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 535.010989] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 535.017104] Lustre: Skipped 2 previous similar messages [ 535.032072] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 552.601499] Lustre: DEBUG MARKER: == replay-single test 100e: DNE: create striped dir on MDT0 and MDT1, fail MDT0, MDT1 ========================================================== 05:57:10 (1769079430) [ 559.250175] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 565.167107] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 566.817652] Lustre: Failing over lustre-MDT0000 [ 566.964791] LustreError: 21325:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 566.973275] LustreError: 21325:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 567.067134] Lustre: server umount lustre-MDT0000 complete [ 569.668655] LustreError: 19155:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.203.15@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 569.686988] LustreError: 19155:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 19 previous similar messages [ 569.774093] LustreError: 6510:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769079448 with bad export cookie 15034836023530971615 [ 569.777803] Lustre: Failing over lustre-MDT0001 [ 569.778939] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 569.781836] LustreError: 6510:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 569.980933] Lustre: server umount lustre-MDT0001 complete [ 591.006400] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 591.009705] LDISKFS-fs (dm-0): recovery complete [ 591.028037] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 591.087688] LDISKFS-fs (dm-1): 5 truncates cleaned up [ 591.089550] LDISKFS-fs (dm-1): recovery complete [ 591.121640] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 594.685115] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 594.689814] Lustre: Skipped 1 previous similar message [ 594.837603] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_connect to node 0@lo failed: rc = -114 [ 595.275701] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 598.170048] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 598.260903] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 600.038487] 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 [ 600.046985] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 600.055742] Lustre: Skipped 2 previous similar messages [ 600.063912] Lustre: Skipped 2 previous similar messages [ 600.883687] Lustre: lustre-MDT0001: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 600.922943] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:161) [ 600.927324] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:70 to 0x2c0000400:161) [ 610.933463] Lustre: lustre-MDT0000: Recovery over after 0:10, of 2 clients 2 recovered and 0 were evicted. [ 610.991261] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:65) [ 610.991642] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:44 to 0x2c0000401:65) [ 614.509368] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 615.879731] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 617.039354] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 624.038802] Lustre: DEBUG MARKER: == replay-single test 101: Shouldn't reassign precreated objs to other files after recovery ========================================================== 05:58:22 (1769079502) [ 626.657973] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079449/real 1769079449] req@ffff9eb9c1d3d880 x1855013737945984/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769079505 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 626.683547] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 629.744926] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 630.752255] Lustre: 3662:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079453/real 1769079453] req@ffff9eb99d54e300 x1855013737946624/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769079509 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 630.770110] Lustre: 3662:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 635.872268] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079458/real 1769079458] req@ffff9eb9861cdf80 x1855013737947136/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769079514 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 635.894447] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 640.993874] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079463/real 1769079463] req@ffff9eb9861cf100 x1855013737948032/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769079519 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 641.028135] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 648.858148] Lustre: Failing over lustre-MDT0000 [ 649.018131] LustreError: 24304:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 649.022911] LustreError: 24304:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 650.912133] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079473/real 1769079473] req@ffff9eb9c1d3f800 x1855013737949056/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769079529 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 650.929994] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 6 previous similar messages [ 651.197647] Lustre: server umount lustre-MDT0000 complete [ 651.240997] 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 [ 651.255675] Lustre: Skipped 4 previous similar messages [ 661.438530] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 661.441426] LDISKFS-fs (dm-0): recovery complete [ 661.454632] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 661.529337] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 661.674651] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 661.678205] Lustre: lustre-MDT0000: Aborting client recovery [ 661.680254] LustreError: 24949:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 661.686674] Lustre: 24982:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 661.686683] Lustre: 24982:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 661.705098] Lustre: 24982:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client ecee0c4e-a258-47c0-b6ca-f609d5a774a7@ [ 661.712748] Lustre: 24982:0:(genops.c:1618:class_disconnect_stale_exports()) Skipped 1 previous similar message [ 661.717487] Lustre: lustre-MDT0000: disconnecting 2 stale clients [ 661.725195] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 661.734821] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 661.768403] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:44 to 0x2c0000401:609) [ 661.771855] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:67 to 0x280000401:609) [ 665.112442] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 667.108908] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 667.117072] Lustre: Skipped 5 previous similar messages [ 738.248167] Lustre: DEBUG MARKER: == replay-single test 102a: check resend (request lost) with multiple modify RPCs in flight ========================================================== 06:00:16 (1769079616) [ 739.519682] Lustre: *** cfs_fail_loc=159, val=0*** [ 794.462088] Lustre: lustre-MDT0001: Client ecee0c4e-a258-47c0-b6ca-f609d5a774a7 (at 192.168.203.15@tcp) reconnecting [ 798.920160] Lustre: DEBUG MARKER: == replay-single test 102b: check resend (reply lost) with multiple modify RPCs in flight ========================================================== 06:01:17 (1769079677) [ 799.872194] Lustre: *** cfs_fail_loc=15a, val=0*** [ 854.829907] Lustre: lustre-MDT0000: Client ecee0c4e-a258-47c0-b6ca-f609d5a774a7 (at 192.168.203.15@tcp) reconnecting [ 854.843394] Lustre: 22639:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9eb9a5395880 x1855013718429440/t17179873234(0) o36->ecee0c4e-a258-47c0-b6ca-f609d5a774a7@192.168.203.15@tcp:23/0 lens 488/3152 e 0 to 0 dl 1769079783 ref 1 fl Interpret:/202/0 rc 0/0 job:'chmod.0' uid:0 gid:0 projid:4294967295 [ 854.866971] Lustre: 22639:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 6 previous similar messages [ 859.564472] Lustre: DEBUG MARKER: == replay-single test 102c: check replay w/o reconstruction with multiple mod RPCs in flight ========================================================== 06:02:17 (1769079737) [ 865.208765] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 865.843260] Lustre: *** cfs_fail_loc=15a, val=0*** [ 865.846203] Lustre: Skipped 7 previous similar messages [ 868.706333] Lustre: Failing over lustre-MDT0001 [ 868.891816] LustreError: 26948:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 868.895548] LustreError: 26948:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 868.963412] Lustre: server umount lustre-MDT0001 complete [ 870.207477] LustreError: 22641:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.15@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 870.228291] LustreError: 22641:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 16 previous similar messages [ 871.913276] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 871.916952] 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 [ 871.934453] Lustre: Skipped 2 previous similar messages [ 887.375961] LDISKFS-fs (dm-1): 7 truncates cleaned up [ 887.378202] LDISKFS-fs (dm-1): recovery complete [ 887.387168] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 887.606235] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 887.610814] Lustre: Skipped 2 previous similar messages [ 887.640371] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 887.642993] Lustre: Skipped 2 previous similar messages [ 889.566197] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 889.570691] Lustre: Skipped 1 previous similar message [ 890.848932] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 892.901800] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 892.911418] Lustre: Skipped 2 previous similar messages [ 892.938055] Lustre: lustre-MDT0001: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 892.986130] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 892.986161] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 896.295463] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 897.325885] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 902.417349] Lustre: DEBUG MARKER: == replay-single test 102d: check replay [ 903.307372] Lustre: *** cfs_fail_loc=15a, val=0*** [ 903.309295] Lustre: Skipped 6 previous similar messages [ 906.526787] Lustre: Failing over lustre-MDT0000 [ 906.695696] Lustre: server umount lustre-MDT0000 complete [ 921.840892] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 921.918467] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 922.115673] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 924.489946] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 925.488790] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 927.236566] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 927.275847] Lustre: 25480:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9eb9ae010700 x1855013718491264/t17179873293(0) o36->ecee0c4e-a258-47c0-b6ca-f609d5a774a7@192.168.203.15@tcp:96/0 lens 512/3152 e 0 to 0 dl 1769079856 ref 1 fl Interpret:/202/0 rc 0/0 job:'chmod.0' uid:0 gid:0 projid:4294967295 [ 927.290844] Lustre: 25480:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 6 previous similar messages [ 927.292379] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1153) [ 927.294426] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1153) [ 929.308030] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 930.202247] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 935.830756] Lustre: DEBUG MARKER: == replay-single test 103: Check otr_next_id overflow ==== 06:03:34 (1769079814) [ 938.763782] Lustre: Failing over lustre-MDT0000 [ 938.926885] LustreError: 29798:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 938.931819] LustreError: 29798:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 939.014818] Lustre: server umount lustre-MDT0000 complete [ 942.561367] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 954.371876] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 954.471293] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 954.646289] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 957.067141] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 959.979437] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 959.984672] Lustre: Skipped 6 previous similar messages [ 960.070241] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1185) [ 960.070333] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1185) [ 962.550988] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 963.720400] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 970.713429] Lustre: DEBUG MARKER: == replay-single test 110a: DNE: create striped dir, fail MDT1 ========================================================== 06:04:08 (1769079848) [ 976.521448] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 977.975511] Lustre: Failing over lustre-MDT0000 [ 978.204132] Lustre: server umount lustre-MDT0000 complete [ 996.833848] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769079859/real 1769079859] req@ffff9eb9c1d53800 x1855013738625408/t0(0) o400->MGC192.168.203.115@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1769079875 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 996.857852] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 996.866123] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 997.480571] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 997.482598] LDISKFS-fs (dm-0): recovery complete [ 997.494060] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1006.053554] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xd0a677b496d2d6a2 [ 1006.296427] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1007.704724] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1007.711610] Lustre: Skipped 1 previous similar message [ 1009.539957] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1011.722936] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 1011.729608] Lustre: Skipped 1 previous similar message [ 1011.764563] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1217) [ 1011.764968] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1217) [ 1014.666204] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1015.685548] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1021.799410] Lustre: DEBUG MARKER: == replay-single test 110b: DNE: create striped dir, fail MDT1 and client ========================================================== 06:05:00 (1769079900) [ 1027.099144] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1028.781757] Lustre: Failing over lustre-MDT0000 [ 1029.029448] Lustre: server umount lustre-MDT0000 complete [ 1032.161369] 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 [ 1032.161522] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1032.172099] Lustre: Skipped 14 previous similar messages [ 1032.176404] LustreError: Skipped 1 previous similar message [ 1046.882552] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1046.884943] LDISKFS-fs (dm-0): recovery complete [ 1046.891394] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1046.964245] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1047.116824] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1049.395124] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1054.404802] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1056.325726] Lustre: lustre-MDT0000: Denying connection for new client a5ac1136-df50-4559-909b-f81b83e93581 (at 192.168.203.15@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 1:06 [ 1061.677102] Lustre: lustre-MDT0000: Denying connection for new client a5ac1136-df50-4559-909b-f81b83e93581 (at 192.168.203.15@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 1:00 [ 1066.796423] Lustre: lustre-MDT0000: Denying connection for new client a5ac1136-df50-4559-909b-f81b83e93581 (at 192.168.203.15@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:55 [ 1071.917555] Lustre: lustre-MDT0000: Denying connection for new client a5ac1136-df50-4559-909b-f81b83e93581 (at 192.168.203.15@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:50 [ 1077.043077] Lustre: lustre-MDT0000: Denying connection for new client a5ac1136-df50-4559-909b-f81b83e93581 (at 192.168.203.15@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:45 [ 1087.279768] Lustre: lustre-MDT0000: Denying connection for new client a5ac1136-df50-4559-909b-f81b83e93581 (at 192.168.203.15@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:35 [ 1087.288784] Lustre: Skipped 1 previous similar message [ 1107.759359] Lustre: lustre-MDT0000: Denying connection for new client a5ac1136-df50-4559-909b-f81b83e93581 (at 192.168.203.15@tcp), waiting for 2 known clients (0 recovered, 1 in progress, and 0 evicted) to recover in 0:14 [ 1107.786214] Lustre: Skipped 3 previous similar messages [ 1122.501105] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1122.503369] Lustre: 33903:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client ecee0c4e-a258-47c0-b6ca-f609d5a774a7@ [ 1122.509669] Lustre: 33903:0:(genops.c:1618:class_disconnect_stale_exports()) Skipped 1 previous similar message [ 1122.514818] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1122.534402] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1122.546150] Lustre: Skipped 11 previous similar messages [ 1122.571389] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1249) [ 1122.571710] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1249) [ 1129.630264] Lustre: DEBUG MARKER: == replay-single test 110c: DNE: create striped dir, fail MDT2 ========================================================== 06:06:47 (1769080007) [ 1133.699609] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1134.811084] Lustre: Failing over lustre-MDT0001 [ 1134.896917] LustreError: 35057:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1134.899329] LustreError: 35057:0:(obd_class.h:479:obd_check_dev()) Skipped 23 previous similar messages [ 1134.970707] Lustre: server umount lustre-MDT0001 complete [ 1138.483106] LustreError: 22641:0:(ldlm_lib.c:1179:target_handle_connect()) lustre-MDT0001: not available for connect from 192.168.203.15@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1138.494161] LustreError: 22641:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 91 previous similar messages [ 1152.332572] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1152.334587] LDISKFS-fs (dm-1): recovery complete [ 1152.342888] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1152.553121] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1152.557473] Lustre: Skipped 4 previous similar messages [ 1152.582126] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1153.677102] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1153.682455] Lustre: Skipped 1 previous similar message [ 1154.858432] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1157.625453] Lustre: lustre-MDT0001: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 1157.632346] Lustre: Skipped 1 previous similar message [ 1157.662757] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:225) [ 1157.663352] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:225) [ 1159.935908] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1160.942578] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1166.106167] Lustre: DEBUG MARKER: == replay-single test 110d: DNE: create striped dir, fail MDT2 and client ========================================================== 06:07:24 (1769080044) [ 1170.319401] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1171.450736] Lustre: Failing over lustre-MDT0001 [ 1171.582454] Lustre: server umount lustre-MDT0001 complete [ 1172.962310] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 1172.968019] LustreError: Skipped 1 previous similar message [ 1188.086455] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1188.088839] LDISKFS-fs (dm-1): recovery complete [ 1188.103114] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1188.375372] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1190.558613] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1194.473251] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1196.100719] Lustre: lustre-MDT0001: Denying connection for new client e321a469-880c-4d8a-9579-209cbcd92634 (at 192.168.203.15@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:07 [ 1196.108543] Lustre: Skipped 2 previous similar messages [ 1262.892272] Lustre: lustre-MDT0001: Denying connection for new client e321a469-880c-4d8a-9579-209cbcd92634 (at 192.168.203.15@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:00 [ 1262.899455] Lustre: Skipped 12 previous similar messages [ 1263.500124] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 1263.503040] Lustre: 37504:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client a5ac1136-df50-4559-909b-f81b83e93581@ [ 1263.510103] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 1263.548175] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:257) [ 1263.548200] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:257) [ 1270.971765] Lustre: DEBUG MARKER: == replay-single test 110e: DNE: create striped dir, uncommit on MDT2, fail client/MDT1/MDT2 ========================================================== 06:09:09 (1769080149) [ 1274.042521] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1277.419728] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1278.309196] Lustre: Failing over lustre-MDT0000 [ 1278.429419] Lustre: server umount lustre-MDT0000 complete [ 1280.190056] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769080159 with bad export cookie 15034836023531199752 [ 1280.191184] Lustre: Failing over lustre-MDT0001 [ 1280.191802] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1280.196240] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1280.329302] Lustre: server umount lustre-MDT0001 complete [ 1296.293439] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1296.297653] LDISKFS-fs (dm-1): recovery complete [ 1296.305406] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1296.307760] LDISKFS-fs (dm-0): recovery complete [ 1296.307945] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1296.318714] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1296.426202] LustreError: 40337:0:(llog.c:1643:llog_backup()) MGC192.168.203.115@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 1296.429972] Lustre: 40337:0:(mgc_request_server.c:732:mgc_llog_local_copy()) MGC192.168.203.115@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 1300.961368] 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 [ 1300.968589] Lustre: Skipped 9 previous similar messages [ 1305.057323] LustreError: 3658:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9eb986675180 x1855013738805504/t0(0) o250->MGC192.168.203.115@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 [ 1305.258724] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1308.365826] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1308.656598] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1310.694647] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1310.703849] Lustre: Skipped 2 previous similar messages [ 1311.706416] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1281) [ 1311.706463] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1281) [ 1314.248737] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1335.264209] Lustre: 3662:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769080159/real 1769080159] req@ffff9eb9881c9c00 x1855013738802048/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769080214 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1335.277897] Lustre: 3662:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 1380.500607] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 1380.508069] Lustre: 40396:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client e321a469-880c-4d8a-9579-209cbcd92634@ [ 1380.514604] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 1380.547167] Lustre: lustre-MDT0001-osp-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1380.550088] Lustre: Skipped 11 previous similar messages [ 1380.572535] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:289) [ 1380.575732] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:289) [ 1387.027588] Lustre: DEBUG MARKER: SKIP: replay-single test_110f skipping excluded test 110f [ 1387.939994] Lustre: DEBUG MARKER: == replay-single test 110g: DNE: create striped dir, uncommit on MDT1, fail client/MDT1/MDT2 ========================================================== 06:11:06 (1769080266) [ 1391.926477] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1396.093306] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1396.950540] Lustre: Failing over lustre-MDT0000 [ 1397.034162] LustreError: 42359:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 1397.037873] LustreError: 42359:0:(obd_class.h:479:obd_check_dev()) Skipped 31 previous similar messages [ 1397.094275] Lustre: server umount lustre-MDT0000 complete [ 1398.831769] LustreError: 19149:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769080277 with bad export cookie 15034836023531203938 [ 1398.832638] Lustre: Failing over lustre-MDT0001 [ 1398.832981] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1398.837244] LustreError: 19149:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1398.952116] Lustre: server umount lustre-MDT0001 complete [ 1415.256793] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1415.259641] LDISKFS-fs (dm-0): recovery complete [ 1415.264959] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1415.290892] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1415.293877] LDISKFS-fs (dm-1): recovery complete [ 1415.299487] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1419.168170] Lustre: 3661:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769080282/real 1769080282] req@ffff9eb9c1abc380 x1855013738873216/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769080298 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1419.177599] Lustre: 3661:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 1426.361909] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1426.454331] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1430.407321] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1430.851731] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1430.860895] Lustre: Skipped 3 previous similar messages [ 1430.882142] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:321) [ 1430.882143] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:321) [ 1432.078475] Lustre: lustre-MDT0000: Denying connection for new client aab658d7-a001-4a7b-9a8a-4877d19f90d7 (at 192.168.203.15@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:07 [ 1432.084566] Lustre: Skipped 13 previous similar messages [ 1499.500168] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1499.503373] Lustre: 43752:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 2f148652-a4b0-405a-a093-c5235b8af2c7@ [ 1499.508634] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1499.529335] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1313) [ 1499.529517] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1313) [ 1508.901070] Lustre: DEBUG MARKER: == replay-single test 111a: DNE: unlink striped dir, fail MDT1 ========================================================== 06:13:07 (1769080387) [ 1512.144365] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1512.937636] Lustre: Failing over lustre-MDT0000 [ 1513.252258] Lustre: server umount lustre-MDT0000 complete [ 1514.977480] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1514.984677] LustreError: Skipped 3 previous similar messages [ 1529.003540] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1529.005105] LDISKFS-fs (dm-0): recovery complete [ 1529.010914] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1529.090268] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1529.236123] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1529.239138] Lustre: Skipped 3 previous similar messages [ 1531.278139] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1534.478958] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1345) [ 1534.479473] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1345) [ 1536.081090] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1536.946427] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1541.668455] Lustre: DEBUG MARKER: == replay-single test 111b: DNE: unlink striped dir, fail MDT2 ========================================================== 06:13:40 (1769080420) [ 1545.370118] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1546.418108] Lustre: Failing over lustre-MDT0001 [ 1546.557945] Lustre: server umount lustre-MDT0001 complete [ 1562.666489] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1562.668503] LDISKFS-fs (dm-1): recovery complete [ 1562.683808] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1564.667735] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1568.229457] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1568.233022] Lustre: Skipped 3 previous similar messages [ 1568.791406] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1638.501186] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 1638.504053] Lustre: 47690:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client aab658d7-a001-4a7b-9a8a-4877d19f90d7@ [ 1638.508879] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 1638.537719] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:353) [ 1638.538490] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:353) [ 1645.391091] Lustre: DEBUG MARKER: == replay-single test 111c: DNE: unlink striped dir, uncommit on MDT1, fail client/MDT1/MDT2 ========================================================== 06:15:24 (1769080524) [ 1649.112557] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1652.634843] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1653.462416] Lustre: Failing over lustre-MDT0000 [ 1653.554276] Lustre: server umount lustre-MDT0000 complete [ 1655.150517] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769080534 with bad export cookie 15034836023531208649 [ 1655.152339] Lustre: Failing over lustre-MDT0001 [ 1655.156407] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 1655.265200] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1655.265219] LustreError: 44512: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. [ 1655.269381] Lustre: Skipped 1 previous similar message [ 1655.277871] LustreError: 44512:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 61 previous similar messages [ 1660.384654] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1660.388445] Lustre: Skipped 1 previous similar message [ 1661.017875] Lustre: server umount lustre-MDT0001 complete [ 1677.072939] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1677.074537] LDISKFS-fs (dm-1): recovery complete [ 1677.081732] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1677.161582] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1677.165679] LDISKFS-fs (dm-0): recovery complete [ 1677.171179] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1677.212329] LustreError: 50507:0:(llog.c:1643:llog_backup()) MGC192.168.203.115@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 1677.217309] Lustre: 50507:0:(mgc_request_server.c:732:mgc_llog_local_copy()) MGC192.168.203.115@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 1680.865576] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xd0a677b496d30b1b [ 1680.976442] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1680.978951] Lustre: Skipped 7 previous similar messages [ 1683.130180] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1684.084852] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1686.168325] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:385) [ 1686.168339] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:385) [ 1688.636952] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1690.143398] Lustre: lustre-MDT0000: Denying connection for new client c0862b71-61f5-4825-bf41-8f394cb13ab2 (at 192.168.203.15@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:05 [ 1690.149270] Lustre: Skipped 28 previous similar messages [ 1755.500177] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 1755.503239] Lustre: 50617:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 6b65cbd3-e740-4d7b-af16-bdb3d6420aa9@ [ 1755.510628] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 1755.537586] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1377) [ 1755.537585] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1377) [ 1761.756670] Lustre: DEBUG MARKER: == replay-single test 111d: DNE: unlink striped dir, uncommit on MDT2, fail client/MDT1/MDT2 ========================================================== 06:17:20 (1769080640) [ 1765.352486] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1769.001163] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1769.995536] Lustre: Failing over lustre-MDT0000 [ 1770.110935] Lustre: server umount lustre-MDT0000 complete [ 1771.848071] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769080650 with bad export cookie 15034836023531211547 [ 1771.851205] Lustre: Failing over lustre-MDT0001 [ 1771.854285] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1771.989918] Lustre: server umount lustre-MDT0001 complete [ 1787.915467] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1787.917809] LDISKFS-fs (dm-0): recovery complete [ 1787.922924] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1787.924932] LDISKFS-fs (dm-1): recovery complete [ 1787.928161] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1787.934908] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1788.042629] LustreError: 53789:0:(llog.c:1643:llog_backup()) MGC192.168.203.115@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 1788.048028] Lustre: 53789:0:(mgc_request_server.c:732:mgc_llog_local_copy()) MGC192.168.203.115@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 1789.408149] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769080652/real 1769080652] req@ffff9eb9b0ccb100 x1855013739092608/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769080668 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1789.418749] Lustre: 3659:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 10 previous similar messages [ 1796.576416] LustreError: 3658:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9eb99d54d500 x1855013739096064/t0(0) o250->MGC192.168.203.115@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 [ 1796.689222] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 1796.697547] Lustre: Skipped 3 previous similar messages [ 1798.547268] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1798.633805] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1802.675740] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1802.995059] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1409) [ 1802.995072] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1409) [ 1872.500187] Lustre: lustre-MDT0001: recovery is timed out, evict stale exports [ 1872.502851] Lustre: 53847:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client c0862b71-61f5-4825-bf41-8f394cb13ab2@ [ 1872.508288] Lustre: lustre-MDT0001: disconnecting 1 stale clients [ 1872.540264] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:417) [ 1872.543108] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:417) [ 1879.733544] Lustre: DEBUG MARKER: == replay-single test 111e: DNE: unlink striped dir, uncommit on MDT2, fail MDT1/MDT2 ========================================================== 06:19:18 (1769080758) [ 1883.660486] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1886.993293] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1887.876459] Lustre: Failing over lustre-MDT0000 [ 1888.101404] Lustre: server umount lustre-MDT0000 complete [ 1889.248703] 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 [ 1889.254420] Lustre: Skipped 25 previous similar messages [ 1889.695112] LustreError: 6510:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769080768 with bad export cookie 15034836023531213731 [ 1889.697260] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1889.697562] Lustre: Failing over lustre-MDT0001 [ 1889.701179] LustreError: 6510:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1889.704810] LustreError: Skipped 2 previous similar messages [ 1889.831861] Lustre: server umount lustre-MDT0001 complete [ 1905.879721] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1905.882456] LDISKFS-fs (dm-1): recovery complete [ 1905.895828] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1905.900215] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1905.904419] LDISKFS-fs (dm-0): recovery complete [ 1905.910433] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1906.034594] LustreError: 57045:0:(llog.c:1643:llog_backup()) MGC192.168.203.115@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 1906.038251] Lustre: 57045:0:(mgc_request_server.c:732:mgc_llog_local_copy()) MGC192.168.203.115@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 1914.853339] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xd0a677b496d31cb0 [ 1914.861782] Lustre: MGC192.168.203.115@tcp: Connection restored to 0@lo (at 0@lo) [ 1914.864443] Lustre: Skipped 26 previous similar messages [ 1916.799405] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1916.924143] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1921.173698] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:449) [ 1921.173865] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:449) [ 1921.213275] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1441) [ 1921.213590] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1441) [ 1922.773657] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1923.550493] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1924.218705] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1928.480261] Lustre: DEBUG MARKER: == replay-single test 111f: DNE: unlink striped dir, uncommit on MDT1, fail MDT1/MDT2 ========================================================== 06:20:07 (1769080807) [ 1932.022407] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1935.306974] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1936.110665] Lustre: Failing over lustre-MDT0000 [ 1936.231556] LustreError: 59078:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 1936.233528] LustreError: 59078:0:(obd_class.h:479:obd_check_dev()) Skipped 79 previous similar messages [ 1936.267246] Lustre: server umount lustre-MDT0000 complete [ 1937.707939] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769080816 with bad export cookie 15034836023531216048 [ 1937.709424] Lustre: Failing over lustre-MDT0001 [ 1937.711698] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1940.961402] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1940.964190] Lustre: Skipped 1 previous similar message [ 1943.009432] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1943.012812] Lustre: Skipped 2 previous similar messages [ 1944.147899] Lustre: server umount lustre-MDT0001 complete [ 1960.332389] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 1960.334163] LDISKFS-fs (dm-1): recovery complete [ 1960.336139] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 1960.341019] LDISKFS-fs (dm-0): recovery complete [ 1960.345571] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1960.348200] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1960.463285] LustreError: 60377:0:(llog.c:1643:llog_backup()) MGC192.168.203.115@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 1960.467501] Lustre: 60377:0:(mgc_request_server.c:732:mgc_llog_local_copy()) MGC192.168.203.115@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 1962.464167] LustreError: 60379:0:(import.c:337:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 1962.464434] LustreError: 3658:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9eb986529880 x1855013739198208/t0(0) o250->MGC192.168.203.115@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 [ 1964.337375] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1964.536543] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1968.523053] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1968.527175] Lustre: Skipped 9 previous similar messages [ 1968.543216] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1473) [ 1968.543341] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1473) [ 1968.592218] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:481) [ 1968.592354] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:481) [ 1970.176149] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 1970.836116] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1971.468925] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1975.760990] Lustre: DEBUG MARKER: == replay-single test 111g: DNE: unlink striped dir, fail MDT1/MDT2 ========================================================== 06:20:54 (1769080854) [ 1979.198383] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1982.558654] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 1983.423496] Lustre: Failing over lustre-MDT0000 [ 1983.461971] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1983.677802] Lustre: server umount lustre-MDT0000 complete [ 1985.254628] LustreError: 9496:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769080864 with bad export cookie 15034836023531218316 [ 1985.255273] Lustre: Failing over lustre-MDT0001 [ 1985.258220] LustreError: 9496:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1985.389468] Lustre: server umount lustre-MDT0001 complete [ 2002.096274] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2002.097834] LDISKFS-fs (dm-1): recovery complete [ 2002.109180] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2002.119042] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2002.131152] LDISKFS-fs (dm-0): recovery complete [ 2002.140446] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2002.232691] LustreError: 63702:0:(llog.c:1643:llog_backup()) MGC192.168.203.115@tcp: failed to open log lustre-sptlrpc: rc = -108 [ 2002.236094] Lustre: 63702:0:(mgc_request_server.c:732:mgc_llog_local_copy()) MGC192.168.203.115@tcp: failed to copy new config lustre-sptlrpc: rc = -108 [ 2010.080516] LustreError: 3658:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9eb882ef1f80 x1855013739240192/t0(0) o250->MGC192.168.203.115@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 [ 2010.089263] LustreError: 3658:0:(client.c:1390:ptlrpc_import_delay_req()) Skipped 1 previous similar message [ 2012.048982] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2012.249637] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2016.402358] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:513) [ 2016.402391] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:513) [ 2016.427814] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1505) [ 2016.428069] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1505) [ 2017.837195] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 2018.573816] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2019.219040] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2023.310296] Lustre: DEBUG MARKER: == replay-single test 112a: DNE: cross MDT rename, fail MDT1 ========================================================== 06:21:42 (1769080902) [ 2024.029439] Lustre: DEBUG MARKER: SKIP: replay-single test_112a needs >= 4 MDTs [ 2024.782703] Lustre: DEBUG MARKER: == replay-single test 112b: DNE: cross MDT rename, fail MDT2 ========================================================== 06:21:43 (1769080903) [ 2025.473655] Lustre: DEBUG MARKER: SKIP: replay-single test_112b needs >= 4 MDTs [ 2026.262910] Lustre: DEBUG MARKER: == replay-single test 112c: DNE: cross MDT rename, fail MDT3 ========================================================== 06:21:44 (1769080904) [ 2027.099116] Lustre: DEBUG MARKER: SKIP: replay-single test_112c needs >= 4 MDTs [ 2027.934114] Lustre: DEBUG MARKER: == replay-single test 112d: DNE: cross MDT rename, fail MDT4 ========================================================== 06:21:46 (1769080906) [ 2028.789344] Lustre: DEBUG MARKER: SKIP: replay-single test_112d needs >= 4 MDTs [ 2029.546499] Lustre: DEBUG MARKER: == replay-single test 112e: DNE: cross MDT rename, fail MDT1 and MDT2 ========================================================== 06:21:48 (1769080908) [ 2030.243632] Lustre: DEBUG MARKER: SKIP: replay-single test_112e needs >= 4 MDTs [ 2030.965958] Lustre: DEBUG MARKER: == replay-single test 112f: DNE: cross MDT rename, fail MDT1 and MDT3 ========================================================== 06:21:49 (1769080909) [ 2031.754841] Lustre: DEBUG MARKER: SKIP: replay-single test_112f needs >= 4 MDTs [ 2032.639387] Lustre: DEBUG MARKER: == replay-single test 112g: DNE: cross MDT rename, fail MDT1 and MDT4 ========================================================== 06:21:51 (1769080911) [ 2033.365893] Lustre: DEBUG MARKER: SKIP: replay-single test_112g needs >= 4 MDTs [ 2034.056918] Lustre: DEBUG MARKER: == replay-single test 112h: DNE: cross MDT rename, fail MDT2 and MDT3 ========================================================== 06:21:52 (1769080912) [ 2034.694457] Lustre: DEBUG MARKER: SKIP: replay-single test_112h needs >= 4 MDTs [ 2035.370784] Lustre: DEBUG MARKER: == replay-single test 112i: DNE: cross MDT rename, fail MDT2 and MDT4 ========================================================== 06:21:54 (1769080914) [ 2035.992949] Lustre: DEBUG MARKER: SKIP: replay-single test_112i needs >= 4 MDTs [ 2036.720353] Lustre: DEBUG MARKER: == replay-single test 112j: DNE: cross MDT rename, fail MDT3 and MDT4 ========================================================== 06:21:55 (1769080915) [ 2037.337987] Lustre: DEBUG MARKER: SKIP: replay-single test_112j needs >= 4 MDTs [ 2038.086967] Lustre: DEBUG MARKER: == replay-single test 112k: DNE: cross MDT rename, fail MDT1,MDT2,MDT3 ========================================================== 06:21:56 (1769080916) [ 2038.784834] Lustre: DEBUG MARKER: SKIP: replay-single test_112k needs >= 4 MDTs [ 2039.549560] Lustre: DEBUG MARKER: == replay-single test 112l: DNE: cross MDT rename, fail MDT1,MDT2,MDT4 ========================================================== 06:21:58 (1769080918) [ 2040.202321] Lustre: DEBUG MARKER: SKIP: replay-single test_112l needs >= 4 MDTs [ 2040.931775] Lustre: DEBUG MARKER: == replay-single test 112m: DNE: cross MDT rename, fail MDT1,MDT3,MDT4 ========================================================== 06:21:59 (1769080919) [ 2041.585182] Lustre: DEBUG MARKER: SKIP: replay-single test_112m needs >= 4 MDTs [ 2042.309877] Lustre: DEBUG MARKER: == replay-single test 112n: DNE: cross MDT rename, fail MDT2,MDT3,MDT4 ========================================================== 06:22:00 (1769080920) [ 2042.983400] Lustre: DEBUG MARKER: SKIP: replay-single test_112n needs >= 4 MDTs [ 2043.816131] Lustre: DEBUG MARKER: == replay-single test 115: failover for create/unlink striped directory ========================================================== 06:22:02 (1769080922) [ 2047.104536] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2048.203437] Lustre: Failing over lustre-MDT0001 [ 2048.399445] Lustre: server umount lustre-MDT0001 complete [ 2063.573814] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2063.575911] LDISKFS-fs (dm-1): recovery complete [ 2063.581375] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2065.464116] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2069.022216] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:545) [ 2069.022283] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:545) [ 2070.420361] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 2071.046419] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2075.375951] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2076.490985] Lustre: Failing over lustre-MDT0000 [ 2076.672825] Lustre: server umount lustre-MDT0000 complete [ 2079.201824] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2079.206078] LustreError: Skipped 8 previous similar messages [ 2091.082246] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2091.083497] LDISKFS-fs (dm-0): recovery complete [ 2091.086672] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2091.307748] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2091.311888] Lustre: Skipped 11 previous similar messages [ 2092.536428] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2096.646624] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1537) [ 2096.646657] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1537) [ 2097.918166] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2098.499665] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2102.254168] Lustre: DEBUG MARKER: == replay-single test 116a: large update log master MDT recovery ========================================================== 06:23:01 (1769080981) [ 2104.924887] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2105.300181] Lustre: *** cfs_fail_loc=1702, val=0*** [ 2106.123119] Lustre: Failing over lustre-MDT0000 [ 2106.311620] Lustre: server umount lustre-MDT0000 complete [ 2121.023568] LDISKFS-fs (dm-0): 4 truncates cleaned up [ 2121.025405] LDISKFS-fs (dm-0): recovery complete [ 2121.033173] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2122.651764] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2126.374464] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1569) [ 2126.374468] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1569) [ 2127.698522] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2128.373928] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2132.509852] Lustre: DEBUG MARKER: == replay-single test 116b: large update log slave MDT recovery ========================================================== 06:23:31 (1769081011) [ 2135.346689] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2135.699342] Lustre: *** cfs_fail_loc=1702, val=0*** [ 2136.517155] Lustre: Failing over lustre-MDT0001 [ 2136.546553] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2136.549980] Lustre: Skipped 3 previous similar messages [ 2136.745943] Lustre: server umount lustre-MDT0001 complete [ 2151.163629] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2151.165250] LDISKFS-fs (dm-1): recovery complete [ 2151.169980] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2152.630141] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2156.542403] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:209 to 0x2c0000400:577) [ 2156.542424] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:577) [ 2157.942239] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 2158.622760] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2162.779165] Lustre: DEBUG MARKER: == replay-single test 117: DNE: cross MDT unlink, fail MDT1 and MDT2 ========================================================== 06:24:01 (1769081041) [ 2163.635780] Lustre: DEBUG MARKER: SKIP: replay-single test_117 needs >= 4 MDTs [ 2164.305699] Lustre: DEBUG MARKER: == replay-single test 118: invalidate osp update will not cause update log corruption ========================================================== 06:24:03 (1769081043) [ 2164.971766] Lustre: *** cfs_fail_loc=1705, val=0*** [ 2168.320764] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2169.083570] Lustre: Failing over lustre-MDT0000 [ 2169.288722] Lustre: server umount lustre-MDT0000 complete [ 2187.232619] Lustre: 3660:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769081050/real 1769081050] req@ffff9eb9b5467b80 x1855013739423616/t0(0) o400->MGC192.168.203.115@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1769081066 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2187.250937] Lustre: 3660:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 29 previous similar messages [ 2190.957379] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 2190.959604] LDISKFS-fs (dm-0): recovery complete [ 2190.969399] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2201.934630] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2203.402101] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1601) [ 2203.404297] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1601) [ 2209.509414] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2212.096629] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2222.558114] Lustre: DEBUG MARKER: == replay-single test 119: timeout of normal replay does not cause DNE replay fails ========================================================== 06:24:59 (1769081099) [ 2234.334288] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2238.663556] Lustre: Failing over lustre-MDT0000 [ 2238.946232] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2238.954650] Lustre: Skipped 2 previous similar messages [ 2239.310531] Lustre: server umount lustre-MDT0000 complete [ 2253.632870] LDISKFS-fs (dm-0): 3 truncates cleaned up [ 2253.636783] LDISKFS-fs (dm-0): recovery complete [ 2253.649766] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2255.149926] Lustre: 63714:0:(ldlm_lib.c:2068:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 60, extend: 0 [ 2257.691298] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2259.424926] Lustre: 8420:0:(ldlm_lib.c:2068:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 60, extend: 0 [ 2259.439554] LustreError: 76700:0:(ldlm_lib.c:2673:replay_request_or_update()) cfs_fail_timeout id 714 sleeping for 65000ms [ 2261.821030] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2324.496332] LustreError: 76700:0:(ldlm_lib.c:2673:replay_request_or_update()) cfs_fail_timeout id 714 awake [ 2324.507454] Lustre: 76700:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 91074a03-82f4-4094-8277-7c3337be0078@192.168.203.15@tcp [ 2324.519233] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2324.522604] Lustre: 76700:0:(ldlm_lib.c:1897:abort_req_replay_queue()) @@@ aborted: req@ffff9eb9b5467800 x1855013718859136/t0(81604378628) o36->91074a03-82f4-4094-8277-7c3337be0078@192.168.203.15@tcp:701/0 lens 528/0 e 7 to 0 dl 1769081216 ref 1 fl Complete:/204/ffffffff rc 0/-1 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 2324.547983] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 2324.560461] Lustre: 76700:0:(ldlm_lib.c:2068:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 60, extend: 1 [ 2324.561480] Lustre: lustre-MDT0000: Denying connection for new client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 1 evicted) already passed deadline 0:09 [ 2324.577231] Lustre: Skipped 27 previous similar messages [ 2324.644437] Lustre: 76700:0:(ldlm_lib.c:2377:target_recovery_overseer()) lustre-MDT0000 recovery is aborted by hard timeout [ 2324.648122] Lustre: 76700:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2324.652498] Lustre: 76700:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 2324.670692] Lustre: lustre-MDT0000-osd: cancel update llog [0x200001b70:0x1:0x0] [ 2324.688426] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240002b11:0x1:0x0] [ 2324.713841] Lustre: 76700:0:(ldlm_lib.c:2931:target_recovery_thread()) too long recovery - read logs [ 2324.716764] LustreError: dumping log to /tmp/lustre-log.1769081203.76700 [ 2324.819523] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1633) [ 2324.820508] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1633) [ 2329.160365] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 62 sec [ 2338.702230] Lustre: DEBUG MARKER: == replay-single test 120: DNE fail abort should stop both normal and DNE replay ========================================================== 06:26:56 (1769081216) [ 2344.072960] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2349.109075] Lustre: Failing over lustre-MDT0000 [ 2350.561954] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2355.454447] Lustre: server umount lustre-MDT0000 complete [ 2356.712866] LustreError: 63715: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. [ 2356.735699] LustreError: 63715:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 162 previous similar messages [ 2364.630868] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2364.633817] LDISKFS-fs (dm-0): recovery complete [ 2364.644735] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2364.906969] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2364.910229] Lustre: Skipped 15 previous similar messages [ 2364.949716] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2364.950128] Lustre: lustre-MDT0000: Aborting client recovery [ 2364.962338] Lustre: Skipped 13 previous similar messages [ 2364.965027] LustreError: 78549:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 2364.981157] Lustre: 78582:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2364.986252] Lustre: 78582:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 1 previous similar message [ 2364.995169] Lustre: lustre-MDT0000-osd: cancel update llog [0x200009870:0x3:0x0] [ 2365.005858] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x2400090a1:0x1:0x0] [ 2365.061922] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1117 to 0x2c0000401:1665) [ 2365.071752] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1665) [ 2368.346857] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2370.033446] LustreError: lustre-MDT0000-osp-MDT0001: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2385.997768] Lustre: DEBUG MARKER: == replay-single test 121: lock replay timed out and race ========================================================== 06:27:43 (1769081263) [ 2388.354151] Lustre: Failing over lustre-MDT0000 [ 2388.731522] Lustre: server umount lustre-MDT0000 complete [ 2392.041837] Lustre: *** cfs_fail_loc=721, val=0*** [ 2392.044210] Lustre: Skipped 7 previous similar messages [ 2393.390379] Lustre: *** cfs_fail_loc=721, val=0*** [ 2395.620215] Lustre: *** cfs_fail_loc=721, val=0*** [ 2395.626927] Lustre: Skipped 11 previous similar messages [ 2396.849747] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2397.984650] Lustre: *** cfs_fail_loc=721, val=0*** [ 2397.987026] Lustre: Skipped 43 previous similar messages [ 2400.248709] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2402.274083] Lustre: *** cfs_fail_loc=721, val=1*** [ 2402.287985] Lustre: Skipped 65 previous similar messages [ 2402.298458] Lustre: *** cfs_fail_loc=721, val=1*** [ 2402.301391] Lustre: Skipped 5 previous similar messages [ 2412.518673] Lustre: *** cfs_fail_loc=721, val=1*** [ 2412.529626] Lustre: Skipped 34 previous similar messages [ 2413.924347] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:54 [ 2429.229987] Lustre: *** cfs_fail_loc=721, val=1*** [ 2429.236102] Lustre: Skipped 57 previous similar messages [ 2430.259104] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:38 [ 2432.481077] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 2432.497089] Lustre: *** cfs_fail_loc=721, val=1*** [ 2446.649178] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:21 [ 2461.996187] Lustre: *** cfs_fail_loc=721, val=1*** [ 2461.997701] Lustre: Skipped 111 previous similar messages [ 2462.006430] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:06 [ 2462.691573] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 2462.704247] Lustre: *** cfs_fail_loc=721, val=1*** [ 2478.388649] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:05 [ 2492.899955] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 2492.914404] Lustre: *** cfs_fail_loc=721, val=1*** [ 2492.916778] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 2493.748573] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:29 [ 2510.133431] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:13 [ 2523.106662] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 2523.117626] Lustre: *** cfs_fail_loc=721, val=1*** [ 2526.510930] Lustre: *** cfs_fail_loc=721, val=1*** [ 2526.514865] Lustre: Skipped 258 previous similar messages [ 2553.312849] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 2553.322636] Lustre: *** cfs_fail_loc=721, val=1*** [ 2553.328261] Lustre: 79986:0:(ldlm_lib.c:2068:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 2553.343573] Lustre: 79986:0:(ldlm_lib.c:2068:extend_recovery_timer()) Skipped 20 previous similar messages [ 2558.263700] Lustre: lustre-MDT0000: Client 91074a03-82f4-4094-8277-7c3337be0078 (at 192.168.203.15@tcp) reconnected, waiting for 2 clients in recovery for 0:20 [ 2558.274330] Lustre: Skipped 2 previous similar messages [ 2583.528147] Lustre: lustre-MDT0000: Received new MDS connection from 0@lo, keep former export from same NID [ 2583.534066] Lustre: 79986:0:(ldlm_lib.c:2068:extend_recovery_timer()) lustre-MDT0000: extended recovery timer reached hard limit: 180, extend: 1 [ 2583.540894] Lustre: 79986:0:(ldlm_lib.c:2377:target_recovery_overseer()) lustre-MDT0000 recovery is aborted by hard timeout [ 2583.551377] Lustre: 79986:0:(ldlm_lib.c:2377:target_recovery_overseer()) Skipped 1 previous similar message [ 2583.559295] Lustre: 79986:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2583.569607] Lustre: 79986:0:(ldlm_lib.c:2387:target_recovery_overseer()) Skipped 2 previous similar messages [ 2583.576780] Lustre: 79986:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 91074a03-82f4-4094-8277-7c3337be0078@192.168.203.15@tcp [ 2583.587609] Lustre: 79986:0:(genops.c:1618:class_disconnect_stale_exports()) Skipped 2 previous similar messages [ 2583.594192] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 2583.599218] Lustre: Skipped 1 previous similar message [ 2583.603360] LustreError: 79986:0:(ldlm_lib.c:1917:abort_lock_replay_queue()) @@@ aborted: req@ffff9eb88df0ce00 x1855013719005952/t0(0) o101->91074a03-82f4-4094-8277-7c3337be0078@192.168.203.15@tcp:0/0 lens 328/0 e 0 to 0 dl 1769081336 ref 1 fl Complete:/240/ffffffff rc 0/-1 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 2583.648249] Lustre: lustre-MDT0000-osd: cancel update llog [0x20000a040:0x1:0x0] [ 2583.667305] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x2400090a2:0x1:0x0] [ 2583.687375] Lustre: 79986:0:(ldlm_lib.c:2931:target_recovery_thread()) too long recovery - read logs [ 2583.692931] LustreError: dumping log to /tmp/lustre-log.1769081462.79986 [ 2583.739982] Lustre: lustre-MDT0000: Recovery over after 3:05, of 2 clients 1 recovered and 1 was evicted. [ 2583.745810] Lustre: Skipped 9 previous similar messages [ 2583.778200] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1667 to 0x2c0000401:1697) [ 2583.781632] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1697) [ 2584.546057] Lustre: lustre-MDT0000-osp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2584.558543] Lustre: Skipped 47 previous similar messages [ 2599.873747] Lustre: DEBUG MARKER: == replay-single test 130a: DoM file create (setstripe) replay ========================================================== 06:31:17 (1769081477) [ 2605.884779] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2607.374533] Lustre: Failing over lustre-MDT0000 [ 2607.473810] LustreError: 81162:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 2607.480681] LustreError: 81162:0:(obd_class.h:479:obd_check_dev()) Skipped 95 previous similar messages [ 2607.577198] Lustre: server umount lustre-MDT0000 complete [ 2609.121223] 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 [ 2609.147532] Lustre: Skipped 47 previous similar messages [ 2625.506863] LustreError: MGC192.168.203.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2625.516071] LustreError: Skipped 8 previous similar messages [ 2627.173027] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2627.175528] LDISKFS-fs (dm-0): recovery complete [ 2627.185236] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2639.010755] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2641.514914] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1667 to 0x2c0000401:1729) [ 2641.517253] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1729) [ 2644.561497] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2645.799772] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2652.694444] Lustre: DEBUG MARKER: == replay-single test 130b: DoM file create (inherited) replay ========================================================== 06:32:10 (1769081530) [ 2658.294289] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2659.990708] Lustre: Failing over lustre-MDT0000 [ 2660.252865] Lustre: server umount lustre-MDT0000 complete [ 2679.719120] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2679.724519] LDISKFS-fs (dm-0): recovery complete [ 2679.735906] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2688.490926] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0xd0a677b496d395e0 [ 2691.502475] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2694.190336] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1667 to 0x2c0000401:1761) [ 2694.191668] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1761) [ 2696.614960] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2697.746401] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2703.755218] Lustre: DEBUG MARKER: == replay-single test 131a: DoM file write lock replay === 06:33:02 (1769081582) [ 2709.005319] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2710.405213] Lustre: Failing over lustre-MDT0000 [ 2710.673176] Lustre: server umount lustre-MDT0000 complete [ 2714.593928] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2714.597473] LustreError: Skipped 6 previous similar messages [ 2727.320667] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2727.322854] LDISKFS-fs (dm-0): recovery complete [ 2727.326996] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2729.260233] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2729.264834] Lustre: Skipped 7 previous similar messages [ 2729.413076] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2732.571018] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1667 to 0x2c0000401:1793) [ 2732.572268] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1117 to 0x280000401:1793) [ 2734.239638] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2734.959398] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2739.510341] Lustre: DEBUG MARKER: SKIP: replay-single test_131b skipping excluded test 131b [ 2740.418919] Lustre: DEBUG MARKER: == replay-single test 132a: PFL new component instantiate replay ========================================================== 06:33:39 (1769081619) [ 2743.750890] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2744.721791] Lustre: Failing over lustre-MDT0000 [ 2744.930502] Lustre: server umount lustre-MDT0000 complete [ 2759.848795] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2759.850277] LDISKFS-fs (dm-0): recovery complete [ 2759.857101] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2761.694257] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2765.315934] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1795 to 0x280000401:1825) [ 2765.316116] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1825) [ 2766.655067] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2767.352385] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2771.280589] Lustre: DEBUG MARKER: == replay-single test 133: check resend of ongoing requests for lwp during failover ========================================================== 06:34:10 (1769081650) [ 2773.486225] Lustre: *** cfs_fail_loc=123, val=2147483648*** [ 2773.488020] Lustre: Skipped 287 previous similar messages [ 2775.121150] Lustre: Failing over lustre-MDT0000 [ 2775.258624] Lustre: server umount lustre-MDT0000 complete [ 2788.623478] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2789.675570] Lustre: lustre-MDT0001: Client 81b11c11-02d9-4ff4-926f-8413ab768387 (at 192.168.203.15@tcp) reconnecting [ 2790.341338] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2793.958208] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000300000400-0x0000000340000400]:1:mdt [ 2793.962391] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000300000400-0x0000000340000400]:1:mdt] [ 2793.979581] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1795 to 0x280000401:1857) [ 2793.979588] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1857) [ 2796.480747] Lustre: DEBUG MARKER: == replay-single test 134: replay creation of a file created in a pool ========================================================== 06:34:35 (1769081675) [ 2805.076419] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2805.994845] Lustre: Failing over lustre-MDT0000 [ 2806.274175] Lustre: server umount lustre-MDT0000 complete [ 2821.146972] LDISKFS-fs (dm-0): 4 truncates cleaned up [ 2821.148684] LDISKFS-fs (dm-0): recovery complete [ 2821.152922] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2822.810557] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2826.757230] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1795 to 0x280000401:1889) [ 2826.757245] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1889) [ 2828.128813] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2828.790284] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2838.611921] Lustre: DEBUG MARKER: == replay-single test 135: Server failure in lock replay phase ========================================================== 06:35:17 (1769081717) [ 2843.079923] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 2844.098735] Lustre: Failing over lustre-OST0000 [ 2844.151149] Lustre: server umount lustre-OST0000 complete [ 2847.182293] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing load_module ../libcfs/libcfs/libcfs [ 2853.934891] LDISKFS-fs (dm-2): 3 truncates cleaned up [ 2853.936756] LDISKFS-fs (dm-2): recovery complete [ 2853.945057] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2856.064861] Lustre: *** cfs_fail_loc=32d, val=20*** [ 2856.066633] Lustre: Skipped 1 previous similar message [ 2856.081254] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2857.997075] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount REPLAY_LOCKS osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2858.599905] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in REPLAY_LOCKS state after 0 sec [ 2859.220298] Lustre: DEBUG MARKER: replay-single test_135: @@@@@@ FAIL: Unexpected sync success [ 2861.655973] Lustre: DEBUG MARKER: == replay-single test 136: MDS to disconnect all OSPs first, then cleanup ldlm ========================================================== 06:35:40 (1769081740) [ 2862.218862] Lustre: DEBUG MARKER: SKIP: replay-single test_136 needs > 2 MDTs [ 2862.895729] Lustre: DEBUG MARKER: == replay-single test 137a: DNE: create under striped dir, fail MDT1 ========================================================== 06:35:41 (1769081741) [ 2872.625664] Lustre: lustre-OST0000: Client 81b11c11-02d9-4ff4-926f-8413ab768387 (at 192.168.203.15@tcp) reconnected, waiting for 3 clients in recovery for 1:23 [ 2872.630027] Lustre: Skipped 1 previous similar message [ 2875.417784] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2876.262729] Lustre: Failing over lustre-MDT0000 [ 2876.470492] Lustre: server umount lustre-MDT0000 complete [ 2891.974883] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2891.976856] LDISKFS-fs (dm-0): recovery complete [ 2891.983207] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2892.076017] Lustre: lustre-MDT0000: Not available for connect from 192.168.203.15@tcp (not set up) [ 2892.080379] Lustre: Skipped 5 previous similar messages [ 2893.683828] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2897.418691] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1921) [ 2897.418693] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1910 to 0x280000401:1953) [ 2898.839106] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2899.564929] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2904.079228] Lustre: DEBUG MARKER: == replay-single test 137b: DNE: create under striped dir, fail MDT2 ========================================================== 06:36:22 (1769081782) [ 2907.545365] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2908.672581] Lustre: Failing over lustre-MDT0001 [ 2908.809906] Lustre: server umount lustre-MDT0001 complete [ 2924.178024] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2924.180616] LDISKFS-fs (dm-1): recovery complete [ 2924.190448] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2925.793656] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2929.665104] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:581 to 0x2c0000400:609) [ 2929.665108] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:609) [ 2931.037411] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 2931.587694] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2935.730064] Lustre: DEBUG MARKER: == replay-single test 137c: DNE: create under striped dir, fail MDT1/MDT2 ========================================================== 06:36:54 (1769081814) [ 2938.580281] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2941.375364] Lustre: DEBUG MARKER: mds2 REPLAY BARRIER on lustre-MDT0001 [ 2942.079119] Lustre: Failing over lustre-MDT0001 [ 2942.304680] Lustre: server umount lustre-MDT0001 complete [ 2943.650906] Lustre: Failing over lustre-MDT0000 [ 2943.875254] Lustre: server umount lustre-MDT0000 complete [ 2958.859482] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 2958.862521] LDISKFS-fs (dm-0): recovery complete [ 2958.864853] LDISKFS-fs (dm-1): 6 truncates cleaned up [ 2958.866075] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2958.867115] LDISKFS-fs (dm-1): recovery complete [ 2958.874640] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2958.997565] LustreError: 23389: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. [ 2959.004906] LustreError: 23389:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 180 previous similar messages [ 2960.628619] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2960.715641] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2961.184079] Lustre: 3660:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1769081824/real 1769081824] req@ffff9eb9b0866680 x1855013739970432/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1769081840 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2961.195807] Lustre: 3660:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 2965.189040] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1910 to 0x280000401:1985) [ 2965.189045] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1953) [ 2965.215421] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:581 to 0x2c0000400:641) [ 2965.215446] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:641) [ 2966.501811] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 2967.091287] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2967.638844] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2971.614047] Lustre: DEBUG MARKER: == replay-single test 200: Dropping one OBD_PING should not cause disconnect ========================================================== 06:37:30 (1769081850) [ 2972.212820] Lustre: DEBUG MARKER: SKIP: replay-single test_200 Need remote client [ 2972.905609] Lustre: DEBUG MARKER: == replay-single test 201: MDT umount cascading disconnects timeouts ========================================================== 06:37:31 (1769081851) [ 2974.581543] LustreError: 99732:0:(tgt_handler.c:1124:tgt_disconnect()) cfs_fail_timeout id 245 sleeping for 8000ms [ 2982.592135] LustreError: 99732:0:(tgt_handler.c:1124:tgt_disconnect()) cfs_fail_timeout id 245 awake [ 2982.597063] Lustre: Failing over lustre-MDT0001 [ 2982.601306] LustreError: 8421:0:(tgt_handler.c:1124:tgt_disconnect()) cfs_fail_timeout id 245 sleeping for 8000ms [ 2982.604849] LustreError: 8421:0:(tgt_handler.c:1124:tgt_disconnect()) Skipped 2 previous similar messages [ 2990.608096] LustreError: 25499:0:(tgt_handler.c:1124:tgt_disconnect()) cfs_fail_timeout id 245 awake [ 2990.610643] LustreError: 25499:0:(tgt_handler.c:1124:tgt_disconnect()) Skipped 1 previous similar message [ 2990.642063] Lustre: server umount lustre-MDT0001 complete [ 2992.428438] LustreError: 25499:0:(tgt_handler.c:1124:tgt_disconnect()) cfs_fail_timeout id 245 sleeping for 8000ms [ 2994.090564] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2994.219633] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2994.222734] Lustre: Skipped 12 previous similar messages [ 2994.234855] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2994.237556] Lustre: Skipped 14 previous similar messages [ 2995.622726] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2997.112120] LustreError: 25499:0:(tgt_handler.c:1124:tgt_disconnect()) cfs_fail_timeout interrupted [ 2999.015204] Lustre: DEBUG MARKER: == replay-single test 202: pfl replay should recovery layout generation ========================================================== 06:37:57 (1769081877) [ 2999.289728] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:209 to 0x280000400:673) [ 2999.290403] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:581 to 0x2c0000400:673) [ 3002.119700] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3002.874037] Lustre: Failing over lustre-MDT0000 [ 3003.106101] Lustre: server umount lustre-MDT0000 complete [ 3017.574509] LDISKFS-fs (dm-0): 2 truncates cleaned up [ 3017.576066] LDISKFS-fs (dm-0): recovery complete [ 3017.578539] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3019.086890] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3022.857969] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:1796 to 0x2c0000401:1985) [ 3022.857972] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:1987 to 0x280000401:2017) [ 3024.039892] Lustre: DEBUG MARKER: oleg315-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3024.590370] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3027.972279] Lustre: DEBUG MARKER: == replay-single test 203: resend can hit original request ========================================================== 06:38:26 (1769081906) [ 3028.420192] LustreError: 99732:0:(mdt_handler.c:2116:mdt_getattr_name_lock()) cfs_fail_timeout id 2403 sleeping for 2000ms [ 3030.504108] LustreError: 99732:0:(mdt_handler.c:2116:mdt_getattr_name_lock()) cfs_fail_timeout id 2403 awake [ 3030.507264] LustreError: 99732:0:(mdt_handler.c:2116:mdt_getattr_name_lock()) Skipped 1 previous similar message [ 3030.511162] Lustre: 99732:0:(service.c:2606:ptlrpc_server_handle_request()) @@@ pause req after reply req@ffff9eb9c1d3c380 x1855013719256960/t0(0) o101->81b11c11-02d9-4ff4-926f-8413ab768387@192.168.203.15@tcp:687/0 lens 592/1888 e 0 to 0 dl 1769081957 ref 1 fl Complete:/600/0 rc 0/0 job:'stat.0' uid:0 gid:0 projid:0 [ 3033.139669] Lustre: DEBUG MARKER: == replay-single test complete, duration 2745 sec ======== 06:38:31 (1769081911) [ 3033.568099] Lustre: 99732:0:(service.c:2608:ptlrpc_server_handle_request()) @@@ continue req@ffff9eb9c1d3c380 x1855013719256960/t0(0) o101->81b11c11-02d9-4ff4-926f-8413ab768387@192.168.203.15@tcp:687/0 lens 592/1888 e 0 to 0 dl 1769081957 ref 1 fl Complete:/600/0 rc 0/0 job:'stat.0' uid:0 gid:0 projid:0 [ 3033.667492] Lustre: DEBUG MARKER: === replay-single: start cleanup 06:38:32 (1769081912) === [ 3035.967902] Lustre: DEBUG MARKER: === replay-single: finish cleanup 06:38:34 (1769081914) === [ 3038.177911] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3038.181042] Lustre: Skipped 10 previous similar messages [ 3043.298982] Lustre: server umount lustre-MDT0000 complete [ 3046.185245] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1769081925 with bad export cookie 15034836023531265664 [ 3046.191819] LustreError: 19153:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3046.310085] Lustre: server umount lustre-MDT0001 complete [ 3059.544356] Lustre: server umount lustre-OST0000 complete [ 3072.927399] Lustre: server umount lustre-OST0001 complete [ 3079.182588] Lustre: DEBUG MARKER: oleg315-server.virtnet: executing unload_modules_local [ 3080.310738] Key type lgssc unregistered [ 3080.461407] LNet: 106729:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3080.464475] LNetError: 106729:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3080.472319] LNet: Removed LNI 192.168.203.115@tcp [ 3080.823132] Key type .llcrypt unregistered [ 3080.824328] Key type ._llcrypt unregistered