[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 700185721 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524576K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001011] APIC: Switch to symmetric I/O mode setup [ 0.003044] x2apic enabled [ 0.004013] Switched APIC routing to physical x2apic. [ 0.005018] kvm-guest: setup PV IPIs [ 0.008550] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009022] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010017] pid_max: default: 32768 minimum: 301 [ 0.012055] LSM: Security Framework initializing [ 0.013056] Yama: becoming mindful. [ 0.014047] SELinux: Initializing. [ 0.015090] *** VALIDATE selinux *** [ 0.025097] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.030517] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.031186] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.032117] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.034072] *** VALIDATE tmpfs *** [ 0.035523] *** VALIDATE proc *** [ 0.037157] *** VALIDATE cgroup *** [ 0.038013] *** VALIDATE cgroup2 *** [ 0.039320] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.041158] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.042012] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.043041] Spectre V2 : User space: Vulnerable [ 0.045004] Speculative Store Bypass: Vulnerable [ 0.048130] debug: unmapping init [mem 0xffffffffa8a59000-0xffffffffa8a60fff] [ 0.051195] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.052827] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.053028] ... version: 2 [ 0.054017] ... bit width: 48 [ 0.055040] ... generic registers: 4 [ 0.056025] ... value mask: 0000ffffffffffff [ 0.057022] ... max period: 00007fffffffffff [ 0.058024] ... fixed-purpose events: 3 [ 0.059016] ... event mask: 000000070000000f [ 0.060403] rcu: Hierarchical SRCU implementation. [ 0.062659] smp: Bringing up secondary CPUs ... [ 0.063804] x86: Booting SMP configuration: [ 0.064041] .... node #0, CPUs: #1 #2 #3 [ 0.067778] smp: Brought up 1 node, 4 CPUs [ 0.069015] smpboot: Max logical packages: 1 [ 0.070020] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.107908] node 0 deferred pages initialised in 35ms [ 0.113121] devtmpfs: initialized [ 0.114303] x86/mm: Memory block size: 128MB [ 0.120944] gcov: version magic: 0x41383552 [ 0.123320] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.124116] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.125453] pinctrl core: initialized pinctrl subsystem [ 0.127251] [ 0.127836] ************************************************************* [ 0.131016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.133018] ** ** [ 0.135019] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.137019] ** ** [ 0.140016] ** This means that this kernel is built to expose internal ** [ 0.142017] ** IOMMU data structures, which may compromise security on ** [ 0.144084] ** your system. ** [ 0.146013] ** ** [ 0.149017] ** If you see this message and you are not debugging the ** [ 0.151013] ** kernel, report this immediately to your vendor! ** [ 0.153016] ** ** [ 0.156018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.158012] ************************************************************* [ 0.160493] NET: Registered protocol family 16 [ 0.162451] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.166078] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.168061] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.172163] cpuidle: using governor menu [ 0.173725] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.176524] PCI: Using configuration type 1 for base access [ 0.178120] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.188025] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.189019] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.191165] cryptd: max_cpu_qlen set to 1000 [ 0.194034] ACPI: Added _OSI(Module Device) [ 0.195042] ACPI: Added _OSI(Processor Device) [ 0.197015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.198016] ACPI: Added _OSI(Processor Aggregator Device) [ 0.203335] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.210632] ACPI: Interpreter enabled [ 0.212076] ACPI: PM: (supports S0 S3 S4 S5) [ 0.213012] ACPI: Using IOAPIC for interrupt routing [ 0.215198] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.220521] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.230805] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.233066] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.236032] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.239103] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.243534] acpiphp: Slot [2] registered [ 0.245141] acpiphp: Slot [5] registered [ 0.247184] acpiphp: Slot [6] registered [ 0.249177] acpiphp: Slot [7] registered [ 0.250161] acpiphp: Slot [8] registered [ 0.252158] acpiphp: Slot [9] registered [ 0.254154] acpiphp: Slot [10] registered [ 0.256295] acpiphp: Slot [3] registered [ 0.258168] acpiphp: Slot [4] registered [ 0.259183] acpiphp: Slot [11] registered [ 0.262152] acpiphp: Slot [12] registered [ 0.263152] acpiphp: Slot [13] registered [ 0.265160] acpiphp: Slot [14] registered [ 0.267214] acpiphp: Slot [15] registered [ 0.269171] acpiphp: Slot [16] registered [ 0.271169] acpiphp: Slot [17] registered [ 0.273093] acpiphp: Slot [18] registered [ 0.274107] acpiphp: Slot [19] registered [ 0.276128] acpiphp: Slot [20] registered [ 0.278155] acpiphp: Slot [21] registered [ 0.279153] acpiphp: Slot [22] registered [ 0.281112] acpiphp: Slot [23] registered [ 0.283123] acpiphp: Slot [24] registered [ 0.285112] acpiphp: Slot [25] registered [ 0.286191] acpiphp: Slot [26] registered [ 0.288155] acpiphp: Slot [27] registered [ 0.289110] acpiphp: Slot [28] registered [ 0.291131] acpiphp: Slot [29] registered [ 0.292103] acpiphp: Slot [30] registered [ 0.294145] acpiphp: Slot [31] registered [ 0.296122] PCI host bridge to bus 0000:00 [ 0.297021] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.299028] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.302027] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.305026] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.307026] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.311043] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.313202] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.316264] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.320923] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.338027] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.344845] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.348031] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.350043] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.353030] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.356731] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.360303] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.365074] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.371194] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.377022] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.391019] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.397024] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.406875] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.418015] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.427136] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.446031] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.462362] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.478017] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.487015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.516015] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.541539] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.551016] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.558016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.585023] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.598672] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.609019] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.621021] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.643017] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.653000] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.660016] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.667017] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.689098] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.699914] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.706016] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.715022] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.740017] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.756000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.759491] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.763441] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.768473] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.770254] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.775061] iommu: Default domain type: Passthrough [ 0.776485] SCSI subsystem initialized [ 0.778142] ACPI: bus type USB registered [ 0.779138] usbcore: registered new interface driver usbfs [ 0.781091] usbcore: registered new interface driver hub [ 0.784087] usbcore: registered new device driver usb [ 0.786194] pps_core: LinuxPPS API ver. 1 registered [ 0.788015] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.791076] PTP clock support registered [ 0.794098] EDAC MC: Ver: 3.0.0 [ 0.796149] PCI: Using ACPI for IRQ routing [ 0.798693] NetLabel: Initializing [ 0.800016] NetLabel: domain hash size = 128 [ 0.801010] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.803117] NetLabel: unlabeled traffic allowed by default [ 0.805188] vgaarb: loaded [ 0.807333] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.809015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.814007] clocksource: Switched to clocksource kvm-clock [ 0.929488] VFS: Disk quotas dquot_6.6.0 [ 0.932075] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.934805] *** VALIDATE ramfs *** [ 0.936185] *** VALIDATE hugetlbfs *** [ 0.937966] pnp: PnP ACPI init [ 0.940896] pnp: PnP ACPI: found 6 devices [ 0.961090] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.964430] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.967038] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.969602] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.972315] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.975042] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.978312] NET: Registered protocol family 2 [ 0.981184] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.987184] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.991457] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.997485] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.001229] TCP: Hash tables configured (established 65536 bind 65536) [ 1.004520] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.008068] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.011333] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.013942] NET: Registered protocol family 1 [ 1.016249] RPC: Registered named UNIX socket transport module. [ 1.018124] RPC: Registered udp transport module. [ 1.019445] RPC: Registered tcp transport module. [ 1.020823] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.022665] NET: Registered protocol family 44 [ 1.023974] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.025528] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.027175] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.029063] PCI: CLS 0 bytes, default 64 [ 1.031200] Unpacking initramfs... [ 2.483717] debug: unmapping init [mem 0xffff98923cc54000-0xffff98923ffbffff] [ 2.487989] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.491363] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.494161] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.033560] Initialise system trusted keyrings [ 3.035637] Key type blacklist registered [ 3.037536] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.046432] zbud: loaded [ 3.049507] *** VALIDATE nfs *** [ 3.051069] *** VALIDATE nfs4 *** [ 3.052984] pstore: using deflate compression [ 3.056949] Platform Keyring initialized [ 3.170782] NET: Registered protocol family 38 [ 3.172669] Key type asymmetric registered [ 3.174060] Asymmetric key parser 'x509' registered [ 3.176050] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.179198] io scheduler mq-deadline registered [ 3.180961] io scheduler kyber registered [ 3.182591] io scheduler bfq registered [ 3.184982] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.188197] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.191422] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.194745] ACPI: Power Button [PWRF] [ 3.200147] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.207381] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.228719] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.239629] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.275420] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.305042] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.333415] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.338681] Non-volatile memory driver v1.3 [ 3.340659] Linux agpgart interface v0.103 [ 3.376735] virtio_blk virtio1: [vda] 149944 512-byte logical blocks (76.8 MB/73.2 MiB) [ 3.379996] vda: detected capacity change from 0 to 76771328 [ 3.395506] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.398337] vdb: detected capacity change from 0 to 1073741824 [ 3.416717] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.420971] vdc: detected capacity change from 0 to 2621440000 [ 3.443065] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.447099] vdd: detected capacity change from 0 to 2621440000 [ 3.472456] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.476157] vde: detected capacity change from 0 to 4294967296 [ 3.494819] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.498140] vdf: detected capacity change from 0 to 4294967296 [ 3.506980] libphy: Fixed MDIO Bus: probed [ 3.513319] usbcore: registered new interface driver usbserial_generic [ 3.516432] usbserial: USB Serial support registered for generic [ 3.519708] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.524731] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.526958] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.530209] mousedev: PS/2 mouse device common for all mice [ 3.532984] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.534680] rtc_cmos 00:05: RTC can wake from S4 [ 3.540211] rtc_cmos 00:05: registered as rtc0 [ 3.541372] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.542523] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.548953] intel_pstate: CPU model not supported [ 3.551599] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.555750] hid: raw HID events driver (C) Jiri Kosina [ 3.558639] usbcore: registered new interface driver usbhid [ 3.561665] usbhid: USB HID core driver [ 3.563269] drop_monitor: Initializing network drop monitor service [ 3.565681] Initializing XFRM netlink socket [ 3.567785] NET: Registered protocol family 10 [ 3.570883] Segment Routing with IPv6 [ 3.573111] NET: Registered protocol family 17 [ 3.575576] mpls_gso: MPLS GSO support [ 3.581864] RAS: Correctable Errors collector initialized. [ 3.584263] AVX version of gcm_enc/dec engaged. [ 3.586428] AES CTR mode by8 optimization enabled [ 3.686101] sched_clock: Marking stable (3686047330, 0)->(4750223453, -1064176123) [ 3.689817] registered taskstats version 1 [ 3.691882] Loading compiled-in X.509 certificates [ 3.695283] zswap: loaded using pool lzo/zbud [ 3.719652] Key type big_key registered [ 3.734987] Key type encrypted registered [ 3.737080] ima: No TPM chip found, activating TPM-bypass! [ 3.739270] ima: Allocated hash algorithm: sha1 [ 3.741078] ima: No architecture policies found [ 3.742929] evm: Initialising EVM extended attributes: [ 3.744762] evm: security.selinux [ 3.746062] evm: security.ima [ 3.747078] evm: security.capability [ 3.748464] evm: HMAC attrs: 0x1 [ 3.751709] rtc_cmos 00:05: setting system clock to 2026-09-07 16:03:06 UTC (1788796986) [ 3.758550] debug: unmapping init [mem 0xffffffffa9a03000-0xffffffffa9bfffff] [ 3.761758] debug: unmapping init [mem 0xffffffffa8782000-0xffffffffa8a58fff] [ 3.766245] Write protecting the kernel read-only data: 28672k [ 3.769597] debug: unmapping init [mem 0xffffffffa6e03000-0xffffffffa6ffffff] [ 3.772579] debug: unmapping init [mem 0xffffffffa7714000-0xffffffffa77fffff] [ 3.813457] 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.823505] systemd[1]: Detected virtualization kvm. [ 3.826108] systemd[1]: Detected architecture x86-64. [ 3.828197] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.853291] systemd[1]: No hostname configured. [ 3.855321] systemd[1]: Set hostname to . [ 3.857721] random: systemd: uninitialized urandom read (16 bytes read) [ 3.860327] systemd[1]: Initializing machine ID from random generator. [ 3.917578] random: ln: uninitialized urandom read (6 bytes read) [ 4.027813] random: systemd: uninitialized urandom read (16 bytes read) [ 4.030993] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 4.036336] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 4.040884] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. [ OK ] Listening on udev Control Socket. [ OK ] Listening on Journal Socket. Starting Journal Service... Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Sockets. [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Slices. [ OK ] Reached target Paths. Starting Setup Virtual Console... Starting Create Volatile Files and Directories... [ OK ] Reached target Timers. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.757296] device-mapper: uevent: version 1.0.3 [ 4.761746] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.534283] random: fast init done [ 5.539273] virtio_net virtio0 ens2: renamed from eth0 [ 5.594052] scsi host0: ata_piix [ 5.598832] scsi host1: ata_piix [ 5.600360] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.602947] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 10.041661] dracut-initqueue[588]: RTNETLINK answers: File exists [ 10.254749] random: crng init done [ 10.256167] 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.812401] 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 target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped target Swap. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.981480] printk: systemd: 24 output lines suppressed due to ratelimiting [ 12.283645] SELinux: Disabled at runtime. [ 12.346387] 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.356346] systemd[1]: Detected virtualization kvm. [ 12.358611] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.869200] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.872882] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.878338] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.885302] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.889182] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.903374] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.908969] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. Starting Remount Root and Kernel File Systems... [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice User and Session Slice. Mounting Huge Pages File System... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Listening on initctl Compatibility Named Pipe. Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target Slices. Mounting Kernel Debug File System... [ OK ] Created slice system-getty.slice. [ OK ] Listening on udev Control Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on udev Kernel Socket. [ 12.993480] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting udev Coldplug all Devices... [ OK ] Created slice system-serial\x2dgetty.slice. Mounting POSIX Message Queue File System... Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Listening on Process Core Dump Socket. [ OK ] Stopped target Initrd File Systems. [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.320139] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.658151] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.668112] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.814231] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.836434] EDAC sbridge: Ver: 1.1.2 [ 15.609329] Key type dns_resolver registered [ 15.925474] NFS: Registering the id_resolver key type [ 15.927881] Key type id_resolver registered [ 15.929705] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting 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 dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ 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... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... 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 oleg450-server login: [ 60.625028] spl: loading out-of-tree module taints kernel. [ 65.439965] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 78.201009] hrtimer: interrupt took 1733205 ns [ 81.473543] Key type ._llcrypt registered [ 81.475976] Key type .llcrypt registered [ 81.642379] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_hostid [ 107.348437] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing load_modules_local [ 109.435463] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 109.469883] alg: No test for adler32 (adler32-zlib) [ 111.544102] Lustre: Lustre: Build Version: 2.17.58_39_gc924a9e [ 112.758699] LNet: Added LNI 192.168.204.150@tcp [8/256/0/180] [ 114.530742] Key type lgssc registered [ 116.641294] Lustre: Echo OBD driver; http://www.lustre.org/ [ 130.952598] vdc: vdc1 vdc9 [ 142.903362] vde: vde1 vde9 [ 142.923160] vde: vde1 vde9 [ 155.290493] vdf: vdf1 vdf9 [ 176.280436] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing load_modules_local [ 187.872630] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 189.224551] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 189.544500] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 189.667764] Lustre: lustre-MDT0000: new disk, initializing [ 190.093729] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 190.170216] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 195.758740] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 201.307914] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 209.191454] Lustre: lustre-OST0000: new disk, initializing [ 209.195492] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 209.200596] Lustre: Skipped 1 previous similar message [ 209.309204] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 215.362187] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 215.395798] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 215.548907] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 216.999592] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 230.737942] Lustre: lustre-OST0001: new disk, initializing [ 230.751455] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 230.979501] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 238.348933] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 238.358901] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 238.569840] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 239.692615] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 255.428908] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 266.210336] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 275.028800] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing check_logdir /tmp/testlogs/ [ 280.654063] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing yml_node [ 286.116221] Lustre: DEBUG MARKER: Client: 2.17.58.39 [ 289.180423] Lustre: DEBUG MARKER: MDS: 2.17.58.39 [ 292.726129] Lustre: DEBUG MARKER: OSS: 2.17.58.39 [ 294.906513] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Mon Sep 7 12:07:56 EDT 2026 [ 315.688184] Lustre: DEBUG MARKER: excepting tests: 59 36 [ 318.159394] Lustre: DEBUG MARKER: === replay-single: start setup 12:08:19 (1788797299) === [ 324.539471] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing check_config_client /mnt/lustre [ 345.294332] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 349.918472] Lustre: 11324:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 354.745596] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 359.587616] Lustre: DEBUG MARKER: === replay-single: finish setup 12:09:00 (1788797340) === [ 362.189418] Lustre: DEBUG MARKER: == replay-single test 0a: empty replay =================== 12:09:03 (1788797343) [ 366.194909] LustreError: 11822:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 367.739787] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 369.945677] Lustre: Failing over lustre-MDT0000 [ 370.480063] Lustre: server umount lustre-MDT0000 complete [ 386.534376] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797353/real 1788797353] req@ffff98929693c380 x1875689702748672/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797369 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 386.538260] 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 [ 386.564502] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 386.587101] Lustre: Skipped 1 previous similar message [ 386.590872] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 392.672245] Lustre: 3314:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797359/real 1788797359] req@ffff9892ae8b8700 x1875689702748928/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797375 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 392.714836] Lustre: 3314:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 397.474666] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 398.369468] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797364/real 1788797364] req@ffff98929693e680 x1875689702749312/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797380 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 398.409291] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 398.865496] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 399.006642] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 402.530141] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797369/real 1788797369] req@ffff9892a011c380 x1875689702749824/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797385 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 402.570270] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 403.615498] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 411.689673] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 414.385077] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 416.330218] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 426.437975] Lustre: DEBUG MARKER: == replay-single test 0b: ensure object created after recover exists. (3284) ========================================================== 12:10:07 (1788797407) [ 429.064262] Lustre: Failing over lustre-OST0000 [ 429.198530] Lustre: server umount lustre-OST0000 complete [ 432.098207] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 434.676037] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 434.706272] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [ 437.219539] LustreError: 6705:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 439.812290] LustreError: 6703:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 442.345807] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 447.463610] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 447.489505] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 449.687651] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 450.033970] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 451.126630] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 451.127344] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 451.160873] Lustre: Skipped 1 previous similar message [ 457.459753] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 468.486478] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 470.539576] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 482.365407] Lustre: DEBUG MARKER: == replay-single test 0c: check replay-barrier =========== 12:11:03 (1788797463) [ 485.989104] LustreError: 14852:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 487.016263] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 489.919862] Lustre: Failing over lustre-MDT0000 [ 490.391522] Lustre: server umount lustre-MDT0000 complete [ 506.849198] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797473/real 1788797473] req@ffff98929767a300 x1875689702782720/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797489 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 506.849918] 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 [ 506.888441] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 506.926689] Lustre: Skipped 1 previous similar message [ 506.937555] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 517.088812] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797483/real 1788797483] req@ffff9892bb7c7800 x1875689702783360/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797499 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 517.163763] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 517.823824] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 524.804321] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 528.109711] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 528.122770] Lustre: lustre-MDT0000: Denying connection for new client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 531.940510] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 533.499934] Lustre: lustre-MDT0000: Denying connection for new client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:55 [ 538.625560] Lustre: lustre-MDT0000: Denying connection for new client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:49 [ 543.730379] Lustre: lustre-MDT0000: Denying connection for new client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:44 [ 548.852757] Lustre: lustre-MDT0000: Denying connection for new client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:39 [ 559.092498] Lustre: lustre-MDT0000: Denying connection for new client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:29 [ 559.118904] Lustre: Skipped 1 previous similar message [ 579.569573] Lustre: lustre-MDT0000: Denying connection for new client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:08 [ 579.592941] Lustre: Skipped 3 previous similar messages [ 588.500386] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 588.511252] Lustre: 15495:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client e508789c-390e-4e02-a401-4c851b17f4fa@ [ 588.529182] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 588.606909] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 588.670986] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:65) [ 588.671952] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:65) [ 599.399297] Lustre: DEBUG MARKER: == replay-single test 0d: expired recovery with no clients ========================================================== 12:13:01 (1788797581) [ 603.448435] LustreError: 16238:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 604.582237] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 606.647883] Lustre: Failing over lustre-MDT0000 [ 606.878120] Lustre: server umount lustre-MDT0000 complete [ 624.993140] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797591/real 1788797591] req@ffff9892ae931180 x1875689702806656/t0(0) o400->MGC192.168.204.150@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1788797607 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 625.057512] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 625.068925] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 625.121104] 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 [ 634.919432] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 634.979818] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 635.886943] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 635.907745] Lustre: Skipped 1 previous similar message [ 640.091858] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 643.000638] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 643.005285] Lustre: lustre-MDT0000: Denying connection for new client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 643.028497] Lustre: Skipped 1 previous similar message [ 650.222783] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 702.500160] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 702.506891] Lustre: 16883:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 4b797fc2-07b0-454f-bb8f-5ed5c79e2277@ [ 702.514052] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 702.571605] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 702.601061] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:97) [ 702.602428] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:97) [ 716.267083] Lustre: DEBUG MARKER: == replay-single test 1: simple create =================== 12:14:56 (1788797696) [ 719.743300] LustreError: 17619:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 720.541804] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 722.274334] Lustre: Failing over lustre-MDT0000 [ 722.646932] Lustre: server umount lustre-MDT0000 complete [ 742.371683] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797709/real 1788797709] req@ffff9892bb7c6300 x1875689702832000/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797725 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 742.397113] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 10 previous similar messages [ 742.402748] 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 [ 742.411679] Lustre: Skipped 1 previous similar message [ 742.993492] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 743.365500] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 743.418519] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 747.338304] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 747.919501] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 751.094400] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 751.232195] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 751.285191] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:129) [ 751.295802] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:129) [ 757.763129] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 759.401645] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 767.581369] Lustre: DEBUG MARKER: == replay-single test 2a: touch ========================== 12:15:49 (1788797749) [ 770.423042] LustreError: 19198:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 771.438944] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 773.573370] Lustre: Failing over lustre-MDT0000 [ 773.879810] Lustre: server umount lustre-MDT0000 complete [ 792.258497] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 792.642446] 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 [ 792.655727] Lustre: Skipped 1 previous similar message [ 792.893808] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 797.981396] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 798.192748] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 798.201733] Lustre: Skipped 1 previous similar message [ 802.292106] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 802.461080] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 802.523392] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:131 to 0x240000400:161) [ 802.529206] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:161) [ 808.730392] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 810.456652] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 818.324084] Lustre: DEBUG MARKER: == replay-single test 2b: touch ========================== 12:16:39 (1788797799) [ 821.332937] LustreError: 20792:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 822.308720] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 824.448692] Lustre: Failing over lustre-MDT0000 [ 824.791254] Lustre: server umount lustre-MDT0000 complete [ 843.707249] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 843.973980] 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 [ 843.990515] Lustre: Skipped 2 previous similar messages [ 844.153408] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 844.158708] Lustre: Skipped 1 previous similar message [ 844.234951] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 845.025283] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797811/real 1788797811] req@ffff9892a90bad80 x1875689702863360/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797827 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 845.048053] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 13 previous similar messages [ 849.382981] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 849.387622] Lustre: Skipped 1 previous similar message [ 849.552931] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 853.499322] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 853.712401] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 853.745197] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:163 to 0x240000400:193) [ 853.745844] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:193) [ 859.955347] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 861.543366] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 869.687935] Lustre: DEBUG MARKER: == replay-single test 2c: setstripe replay =============== 12:17:31 (1788797851) [ 872.982673] LustreError: 22375:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 874.221916] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 876.449715] Lustre: Failing over lustre-MDT0000 [ 878.835174] Lustre: server umount lustre-MDT0000 complete [ 895.393782] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 895.433199] 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 [ 905.721283] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b77561ac3 [ 906.424655] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 911.067735] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 920.054859] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 920.239850] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 920.324040] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:225) [ 920.325768] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:225) [ 920.549808] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 920.553353] Lustre: Skipped 2 previous similar messages [ 925.727409] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 927.319588] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 936.037574] Lustre: DEBUG MARKER: == replay-single test 2d: setdirstripe replay ============ 12:18:37 (1788797917) [ 939.460892] LustreError: 23979:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 940.571969] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 943.192870] Lustre: Failing over lustre-MDT0000 [ 943.445981] Lustre: server umount lustre-MDT0000 complete [ 961.504238] 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 [ 961.506715] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 961.527865] Lustre: Skipped 1 previous similar message [ 972.275976] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 972.281062] Lustre: Skipped 1 previous similar message [ 972.340078] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 973.285691] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788797939/real 1788797939] req@ffff9892a90b9c00 x1875689702895360/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788797955 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 973.308913] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 20 previous similar messages [ 977.159318] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 986.617911] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 986.755473] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 986.830202] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:257) [ 986.832077] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:257) [ 993.180041] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 994.921587] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1004.537722] Lustre: DEBUG MARKER: == replay-single test 2e: O_CREAT|O_EXCL create replay === 12:19:46 (1788797986) [ 1005.706769] Lustre: *** cfs_fail_loc=13b, val=315*** [ 1005.709026] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 1005.718317] LustreError: 24600:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9892bbd71f80 x1875689676594048/t38654705666(0) o35->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:665/0 lens 392/456 e 0 to 0 dl 1788798005 ref 1 fl Interpret:/600/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 1010.157938] LustreError: 25635:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1011.214441] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1013.200986] Lustre: Failing over lustre-MDT0000 [ 1013.506610] Lustre: server umount lustre-MDT0000 complete [ 1032.419511] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1032.674211] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 1033.085123] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1037.598465] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:289) [ 1037.604328] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:289) [ 1037.622748] Lustre: 26235:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff98928695b100 x1875689676594048/t38654705666(0) o35->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:697/0 lens 392/456 e 0 to 0 dl 1788798037 ref 1 fl Interpret:/602/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 1037.973398] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1047.434363] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1049.183348] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1058.138135] Lustre: DEBUG MARKER: == replay-single test 3a: replay failed open(O_DIRECTORY) ========================================================== 12:20:39 (1788798039) [ 1062.318438] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1064.203635] Lustre: Failing over lustre-MDT0000 [ 1064.486562] Lustre: server umount lustre-MDT0000 complete [ 1083.416231] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1084.177522] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:321) [ 1084.178842] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:321) [ 1088.442141] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1088.489281] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1088.497962] Lustre: Skipped 5 previous similar messages [ 1098.956269] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1100.886245] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1109.301576] Lustre: DEBUG MARKER: == replay-single test 3b: replay failed open -ENOMEM ===== 12:21:30 (1788798090) [ 1113.074614] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1114.133994] Lustre: *** cfs_fail_loc=114, val=0*** [ 1117.020612] Lustre: Failing over lustre-MDT0000 [ 1117.377520] Lustre: server umount lustre-MDT0000 complete [ 1134.561868] 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 [ 1134.583140] Lustre: Skipped 5 previous similar messages [ 1145.338302] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1145.346385] Lustre: Skipped 2 previous similar messages [ 1145.413283] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1145.423734] Lustre: Skipped 2 previous similar messages [ 1145.444672] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:353) [ 1145.444693] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:353) [ 1149.753955] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1159.319687] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1161.425959] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1171.244669] Lustre: DEBUG MARKER: == replay-single test 3c: replay failed open -ENOMEM ===== 12:22:32 (1788798152) [ 1174.524906] LustreError: 30482:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1174.529814] LustreError: 30482:0:(osd_handler.c:720:osd_ro()) Skipped 2 previous similar messages [ 1175.318344] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1176.292716] Lustre: *** cfs_fail_loc=128, val=0*** [ 1179.277328] Lustre: Failing over lustre-MDT0000 [ 1179.569652] Lustre: server umount lustre-MDT0000 complete [ 1195.491056] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1195.502957] LustreError: Skipped 2 previous similar messages [ 1205.730979] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892bbd69c00 x1875689702960768/t0(0) o250->MGC192.168.204.150@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 [ 1206.203485] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1206.209826] Lustre: Skipped 1 previous similar message [ 1207.959346] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:385) [ 1207.972108] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:385) [ 1212.217072] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1223.039908] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1224.842446] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1233.594343] Lustre: DEBUG MARKER: == replay-single test 4a: |x| 10 open(O_CREAT)s ========== 12:23:35 (1788798215) [ 1236.995353] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1239.091713] Lustre: Failing over lustre-MDT0000 [ 1239.401104] Lustre: server umount lustre-MDT0000 complete [ 1256.288191] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788798223/real 1788798223] req@ffff989297699180 x1875689702975488/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788798239 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1256.322354] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 27 previous similar messages [ 1266.656968] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff98929769b800 x1875689702977024/t0(0) o250->MGC192.168.204.150@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 [ 1267.269725] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1267.275395] Lustre: Skipped 4 previous similar messages [ 1269.638125] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:391 to 0x280000400:417) [ 1269.638393] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:391 to 0x240000400:417) [ 1272.977893] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1284.024895] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1285.835787] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1294.591767] Lustre: DEBUG MARKER: == replay-single test 4b: |x| rm 10 files ================ 12:24:36 (1788798276) [ 1299.188699] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1301.796075] Lustre: Failing over lustre-MDT0000 [ 1301.987579] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1301.996712] Lustre: Skipped 2 previous similar messages [ 1302.094090] Lustre: server umount lustre-MDT0000 complete [ 1332.651356] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b77564197 [ 1338.707432] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1343.248146] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:423 to 0x280000400:449) [ 1343.250250] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:423 to 0x240000400:449) [ 1349.097813] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1351.242693] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1361.554747] Lustre: DEBUG MARKER: == replay-single test 5: |x| 220 open(O_CREAT) =========== 12:25:42 (1788798342) [ 1365.998725] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1374.952080] Lustre: Failing over lustre-MDT0000 [ 1375.319233] Lustre: server umount lustre-MDT0000 complete [ 1392.608391] 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 [ 1392.626692] Lustre: Skipped 7 previous similar messages [ 1403.546954] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1403.559968] Lustre: Skipped 2 previous similar messages [ 1404.421918] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1404.438535] Lustre: Skipped 3 previous similar messages [ 1409.434676] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1409.887385] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 1409.901473] Lustre: Skipped 3 previous similar messages [ 1409.987872] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:577) [ 1409.989869] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:577) [ 1417.647666] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1417.662242] Lustre: Skipped 10 previous similar messages [ 1421.769353] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1423.753413] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1452.363661] Lustre: DEBUG MARKER: == replay-single test 6a: mkdir + contained create ======= 12:27:13 (1788798433) [ 1455.710705] LustreError: 36993:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1455.715473] LustreError: 36993:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 1456.590474] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1458.364151] Lustre: Failing over lustre-MDT0000 [ 1458.677072] LustreError: 35962:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1458.700710] LustreError: 35962:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 1458.763065] Lustre: server umount lustre-MDT0000 complete [ 1477.143276] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1477.159889] LustreError: Skipped 3 previous similar messages [ 1481.939072] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1486.440181] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:609) [ 1486.440300] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:609) [ 1492.347200] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1493.879529] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1504.776415] Lustre: DEBUG MARKER: == replay-single test 6b: |X| rmdir ====================== 12:28:06 (1788798486) [ 1508.316623] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1510.516733] Lustre: Failing over lustre-MDT0000 [ 1510.866196] Lustre: server umount lustre-MDT0000 complete [ 1534.031452] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1537.666617] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:641) [ 1537.670792] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:641) [ 1543.061398] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1544.744685] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1552.647395] Lustre: DEBUG MARKER: == replay-single test 7: mkdir |X| contained create ====== 12:28:54 (1788798534) [ 1557.167173] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1559.215843] Lustre: Failing over lustre-MDT0000 [ 1559.584033] Lustre: server umount lustre-MDT0000 complete [ 1587.169216] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892bab5b100 x1875689703122944/t0(0) o250->MGC192.168.204.150@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 [ 1589.902092] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:673) [ 1589.903871] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:673) [ 1591.073625] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1599.610294] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1601.483934] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1609.786231] Lustre: DEBUG MARKER: == replay-single test 8: creat open |X| close ============ 12:29:51 (1788798591) [ 1613.820378] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1616.106220] Lustre: Failing over lustre-MDT0000 [ 1616.597754] Lustre: server umount lustre-MDT0000 complete [ 1643.875600] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892bab49180 x1875689703138304/t0(0) o250->MGC192.168.204.150@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 [ 1646.433409] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:705) [ 1646.436670] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:705) [ 1648.948263] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1657.723352] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1659.248915] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1668.817713] Lustre: DEBUG MARKER: == replay-single test 9: |X| create (same inum/gen) ====== 12:30:49 (1788798649) [ 1674.674975] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1676.677863] Lustre: Failing over lustre-MDT0000 [ 1676.814100] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.50@tcp (stopping) [ 1677.149349] Lustre: server umount lustre-MDT0000 complete [ 1706.573323] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1706.581632] Lustre: Skipped 4 previous similar messages [ 1711.271258] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1716.962793] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:737) [ 1716.967252] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:737) [ 1722.116646] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1723.645179] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1731.377732] Lustre: DEBUG MARKER: == replay-single test 10: create |X| rename unlink ======= 12:31:52 (1788798712) [ 1735.287508] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1737.354347] Lustre: Failing over lustre-MDT0000 [ 1737.714821] Lustre: server umount lustre-MDT0000 complete [ 1757.661596] Lustre: MGS: Not available for connect from 0@lo (not set up) [ 1759.000761] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:769) [ 1759.003294] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:769) [ 1763.309753] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1772.640498] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788798739/real 1788798739] req@ffff98929768bb80 x1875689703170688/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788798755 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1772.671333] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 60 previous similar messages [ 1774.214760] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1776.248503] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1784.777535] Lustre: DEBUG MARKER: == replay-single test 11: create open write rename |X| create-old-name read ========================================================== 12:32:46 (1788798766) [ 1789.231168] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1791.477644] Lustre: Failing over lustre-MDT0000 [ 1791.798347] Lustre: server umount lustre-MDT0000 complete [ 1820.136419] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff989297678a80 x1875689703187584/t0(0) o250->MGC192.168.204.150@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 [ 1820.635509] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1820.639565] Lustre: Skipped 8 previous similar messages [ 1824.776246] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1835.803217] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:801) [ 1835.805313] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:801) [ 1841.232989] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1842.814486] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1850.291328] Lustre: DEBUG MARKER: == replay-single test 12: open, unlink |X| close ========= 12:33:52 (1788798832) [ 1854.013864] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1856.385215] Lustre: Failing over lustre-MDT0000 [ 1856.878568] Lustre: server umount lustre-MDT0000 complete [ 1875.938866] LustreError: 48727:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1877.021407] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:833) [ 1877.026685] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:833) [ 1882.590495] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1892.949955] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1894.673205] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1903.067929] Lustre: DEBUG MARKER: == replay-single test 13: open chmod 0 |x| write close === 12:34:44 (1788798884) [ 1907.401737] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1909.530806] Lustre: Failing over lustre-MDT0000 [ 1909.897101] Lustre: server umount lustre-MDT0000 complete [ 1928.674000] 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 [ 1928.687385] Lustre: Skipped 18 previous similar messages [ 1938.913731] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff989297678700 x1875689703219968/t0(0) o250->MGC192.168.204.150@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 [ 1943.944536] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1953.269060] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1953.274768] Lustre: Skipped 8 previous similar messages [ 1953.437822] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1953.445143] Lustre: Skipped 8 previous similar messages [ 1953.492257] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:865) [ 1953.492290] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:835 to 0x240000400:865) [ 1953.583976] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1953.588832] Lustre: Skipped 17 previous similar messages [ 1958.657861] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1959.921254] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1966.821354] Lustre: DEBUG MARKER: == replay-single test 14: open(O_CREAT), unlink |X| close ========================================================== 12:35:48 (1788798948) [ 1969.456463] LustreError: 51302:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1969.462459] LustreError: 51302:0:(osd_handler.c:720:osd_ro()) Skipped 8 previous similar messages [ 1970.322810] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1972.036248] Lustre: Failing over lustre-MDT0000 [ 1972.210936] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1972.219066] Lustre: Skipped 1 previous similar message [ 1972.434025] Lustre: server umount lustre-MDT0000 complete [ 1990.337639] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1990.346733] LustreError: Skipped 8 previous similar messages [ 1994.919750] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2000.484277] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:835 to 0x240000400:897) [ 2000.485227] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:867 to 0x280000400:897) [ 2005.924859] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2007.182984] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2014.530178] Lustre: DEBUG MARKER: == replay-single test 15: open(O_CREAT), unlink |X| touch new, close ========================================================== 12:36:36 (1788798996) [ 2018.645479] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2020.499221] Lustre: Failing over lustre-MDT0000 [ 2020.808599] Lustre: server umount lustre-MDT0000 complete [ 2044.170413] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2046.654336] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:929) [ 2046.654575] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:899 to 0x240000400:929) [ 2053.447945] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2054.997842] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2062.939940] Lustre: DEBUG MARKER: == replay-single test 16: |X| open(O_CREAT), unlink, touch new, unlink new ========================================================== 12:37:24 (1788799044) [ 2066.848468] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2068.628773] Lustre: Failing over lustre-MDT0000 [ 2068.959292] Lustre: server umount lustre-MDT0000 complete [ 2087.683755] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:961) [ 2087.683820] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:931 to 0x240000400:961) [ 2090.341873] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2098.479774] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2100.118542] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2108.551594] Lustre: DEBUG MARKER: == replay-single test 17: |X| open(O_CREAT), |replay| close ========================================================== 12:38:10 (1788799090) [ 2112.834574] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2114.986096] Lustre: Failing over lustre-MDT0000 [ 2115.319386] Lustre: server umount lustre-MDT0000 complete [ 2142.690443] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892baae8700 x1875689703281536/t0(0) o250->MGC192.168.204.150@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 [ 2145.005611] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:931 to 0x240000400:993) [ 2145.009502] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:963 to 0x280000400:993) [ 2148.133175] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2157.880564] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2159.390955] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2169.530370] Lustre: DEBUG MARKER: == replay-single test 18: open(O_CREAT), unlink, touch new, close, touch, unlink ========================================================== 12:39:10 (1788799150) [ 2173.939983] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2176.153140] Lustre: Failing over lustre-MDT0000 [ 2176.522762] Lustre: server umount lustre-MDT0000 complete [ 2203.616967] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff98929eb90a80 x1875689703298432/t0(0) o250->MGC192.168.204.150@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 [ 2206.494124] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:995 to 0x240000400:1025) [ 2206.495834] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:995 to 0x280000400:1025) [ 2209.070226] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2218.878618] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2220.891563] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2230.337123] Lustre: DEBUG MARKER: == replay-single test 19: mcreate, open, write, rename === 12:40:11 (1788799211) [ 2234.576354] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2236.830867] Lustre: Failing over lustre-MDT0000 [ 2236.921802] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.50@tcp (stopping) [ 2237.279889] Lustre: server umount lustre-MDT0000 complete [ 2264.486786] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b7757214a [ 2265.099916] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2265.117471] Lustre: Skipped 9 previous similar messages [ 2270.349249] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2278.171457] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1027 to 0x240000400:1057) [ 2278.171987] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1057) [ 2284.327981] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2285.675523] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2295.582766] Lustre: DEBUG MARKER: == replay-single test 20a: |X| open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 12:41:16 (1788799276) [ 2300.022737] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2302.527968] Lustre: Failing over lustre-MDT0000 [ 2302.970734] Lustre: server umount lustre-MDT0000 complete [ 2332.642111] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892bbd6b100 x1875689703333248/t0(0) o250->MGC192.168.204.150@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 [ 2332.674327] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) Skipped 2 previous similar messages [ 2338.570893] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2344.347172] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1089) [ 2344.349405] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1059 to 0x240000400:1089) [ 2350.829396] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2352.284255] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2360.492362] Lustre: DEBUG MARKER: == replay-single test 20b: write, unlink, eviction, replay (test mds_cleanup_orphans) ========================================================== 12:42:22 (1788799342) [ 2365.820045] Lustre: 62508:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 554b761e-e6ad-477b-bb92-ebd389a807c6 at adminstrative request [ 2372.583782] Lustre: Failing over lustre-MDT0000 [ 2372.890822] Lustre: server umount lustre-MDT0000 complete [ 2388.449387] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788799355/real 1788799355] req@ffff989297679f80 x1875689703349504/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788799371 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2388.481669] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 78 previous similar messages [ 2401.901456] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1091 to 0x240000400:1121) [ 2401.902332] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1121) [ 2403.179768] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2413.110804] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2414.702295] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2418.998985] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2430.669661] Lustre: DEBUG MARKER: before 4096, after 4096 [ 2436.771584] Lustre: DEBUG MARKER: == replay-single test 20c: check that client eviction does not affect file content ========================================================== 12:43:38 (1788799418) [ 2437.670668] Lustre: 64595:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 554b761e-e6ad-477b-bb92-ebd389a807c6 at adminstrative request [ 2446.468078] Lustre: DEBUG MARKER: == replay-single test 21: |X| open(O_CREAT), unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 12:43:48 (1788799428) [ 2449.994592] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2451.759755] Lustre: Failing over lustre-MDT0000 [ 2452.146992] Lustre: server umount lustre-MDT0000 complete [ 2469.863697] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff989182da5500 x1875689703370880/t0(0) o250->MGC192.168.204.150@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 [ 2470.337732] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2470.342635] Lustre: Skipped 10 previous similar messages [ 2471.700659] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1123 to 0x280000400:1153) [ 2471.701601] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1124 to 0x240000400:1153) [ 2474.706178] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2485.116831] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2486.723834] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2495.050554] Lustre: DEBUG MARKER: == replay-single test 22: open(O_CREAT), |X| unlink, replay, close (test mds_cleanup_orphans) ========================================================== 12:44:36 (1788799476) [ 2498.381843] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2500.381565] Lustre: Failing over lustre-MDT0000 [ 2500.618903] Lustre: server umount lustre-MDT0000 complete [ 2526.692979] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b775734d7 [ 2528.900244] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1155 to 0x280000400:1185) [ 2528.900272] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1155 to 0x240000400:1185) [ 2532.106803] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2541.080887] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2542.730880] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2550.703427] Lustre: DEBUG MARKER: == replay-single test 23: open(O_CREAT), |X| unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 12:45:32 (1788799532) [ 2554.533299] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2556.656499] Lustre: Failing over lustre-MDT0000 [ 2556.900531] 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 [ 2556.909550] Lustre: Skipped 21 previous similar messages [ 2556.911859] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2557.030500] Lustre: server umount lustre-MDT0000 complete [ 2575.864327] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2575.874529] Lustre: Skipped 10 previous similar messages [ 2576.035825] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2576.046130] Lustre: Skipped 10 previous similar messages [ 2576.081112] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1187 to 0x240000400:1217) [ 2576.081112] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1187 to 0x280000400:1217) [ 2576.484838] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2576.490043] Lustre: Skipped 23 previous similar messages [ 2579.143222] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2587.932692] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2589.393568] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2597.260582] Lustre: DEBUG MARKER: == replay-single test 24: open(O_CREAT), replay, unlink, close (test mds_cleanup_orphans) ========================================================== 12:46:18 (1788799578) [ 2600.718862] LustreError: 69722:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2600.728042] LustreError: 69722:0:(osd_handler.c:720:osd_ro()) Skipped 9 previous similar messages [ 2601.783446] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2603.728258] Lustre: Failing over lustre-MDT0000 [ 2604.061727] Lustre: server umount lustre-MDT0000 complete [ 2623.442694] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2623.455991] LustreError: Skipped 10 previous similar messages [ 2629.730554] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2632.379347] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1219 to 0x240000400:1249) [ 2632.379644] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1219 to 0x280000400:1249) [ 2640.813833] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2642.278536] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2652.379031] Lustre: DEBUG MARKER: == replay-single test 25: open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 12:47:13 (1788799633) [ 2656.822675] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2658.798507] Lustre: Failing over lustre-MDT0000 [ 2659.090080] Lustre: server umount lustre-MDT0000 complete [ 2688.714871] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1251 to 0x240000400:1281) [ 2688.716546] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1219 to 0x280000400:1281) [ 2690.975355] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2701.113304] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2702.590959] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2711.178125] Lustre: DEBUG MARKER: == replay-single test 26: |X| open(O_CREAT), unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 12:48:12 (1788799692) [ 2715.219316] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2717.922341] Lustre: Failing over lustre-MDT0000 [ 2718.320492] Lustre: server umount lustre-MDT0000 complete [ 2751.226787] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2760.368916] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1283 to 0x280000400:1313) [ 2760.377576] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1283 to 0x240000400:1313) [ 2766.120444] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2768.274528] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2777.694510] Lustre: DEBUG MARKER: == replay-single test 27: |X| open(O_CREAT), unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 12:49:18 (1788799758) [ 2781.820587] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2784.036973] Lustre: Failing over lustre-MDT0000 [ 2784.381146] Lustre: server umount lustre-MDT0000 complete [ 2808.725967] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2811.629352] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1315 to 0x280000400:1345) [ 2811.632114] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1315 to 0x240000400:1345) [ 2819.478359] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2821.390598] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2829.756745] Lustre: DEBUG MARKER: == replay-single test 28: open(O_CREAT), |X| unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 12:50:11 (1788799811) [ 2834.399215] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2836.804231] Lustre: Failing over lustre-MDT0000 [ 2836.997305] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.50@tcp (stopping) [ 2837.003941] Lustre: Skipped 1 previous similar message [ 2839.261833] Lustre: server umount lustre-MDT0000 complete [ 2866.665931] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b7757538c [ 2867.402036] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2867.408070] Lustre: Skipped 9 previous similar messages [ 2872.489699] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2878.209132] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1347 to 0x280000400:1377) [ 2878.209596] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1347 to 0x240000400:1377) [ 2883.680605] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2885.064673] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2892.815444] Lustre: DEBUG MARKER: == replay-single test 29: open(O_CREAT), |X| unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 12:51:14 (1788799874) [ 2896.294162] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2898.267629] Lustre: Failing over lustre-MDT0000 [ 2898.640355] Lustre: server umount lustre-MDT0000 complete [ 2919.113680] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1379 to 0x280000400:1409) [ 2919.113957] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1379 to 0x240000400:1409) [ 2920.852835] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2930.413970] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2931.820300] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2940.207348] Lustre: DEBUG MARKER: == replay-single test 30: open(O_CREAT) two, unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 12:52:01 (1788799921) [ 2943.971882] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2945.505375] Lustre: Failing over lustre-MDT0000 [ 2945.768549] Lustre: server umount lustre-MDT0000 complete [ 2965.208509] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1411 to 0x240000400:1441) [ 2965.214895] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1411 to 0x280000400:1441) [ 2969.191445] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2980.072807] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2981.619062] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2991.687129] Lustre: DEBUG MARKER: == replay-single test 31: open(O_CREAT) two, unlink one, |X| unlink one, close two (test mds_cleanup_orphans) ========================================================== 12:52:52 (1788799972) [ 2995.913377] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2998.086703] Lustre: Failing over lustre-MDT0000 [ 2998.565240] Lustre: server umount lustre-MDT0000 complete [ 3016.161357] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788799982/real 1788799982] req@ffff9892a0566d80 x1875689703529600/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788799998 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3016.216339] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 78 previous similar messages [ 3025.377273] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892bb346a00 x1875689703531648/t0(0) o250->MGC192.168.204.150@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 [ 3026.625582] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1443 to 0x240000400:1473) [ 3026.628530] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1443 to 0x280000400:1473) [ 3031.228873] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3042.095840] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3043.975718] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3052.981973] Lustre: DEBUG MARKER: == replay-single test 32: close() notices client eviction; close() after client eviction ========================================================== 12:53:54 (1788800034) [ 3054.211652] Lustre: 82358:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 554b761e-e6ad-477b-bb92-ebd389a807c6 at adminstrative request [ 3065.997118] Lustre: DEBUG MARKER: == replay-single test 33a: fid seq shouldn't be reused after abort recovery ========================================================== 12:54:07 (1788800047) [ 3069.118876] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3070.906050] Lustre: Failing over lustre-MDT0000 [ 3071.182099] Lustre: server umount lustre-MDT0000 complete [ 3081.810636] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3081.815202] Lustre: Skipped 10 previous similar messages [ 3081.902795] Lustre: lustre-MDT0000: Aborting client recovery [ 3081.906553] LustreError: 83265:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3081.913082] Lustre: 83315:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3081.918530] Lustre: 83315:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 554b761e-e6ad-477b-bb92-ebd389a807c6@ [ 3081.927589] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3081.978796] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 3082.105483] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1479 to 0x280000400:1505) [ 3082.117163] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1480 to 0x240000400:1505) [ 3087.145928] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3101.568418] Lustre: DEBUG MARKER: == replay-single test 33b: test fid seq allocation ======= 12:54:42 (1788800082) [ 3105.626944] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3107.583754] Lustre: Failing over lustre-MDT0000 [ 3108.018310] Lustre: server umount lustre-MDT0000 complete [ 3117.537702] LustreError: 84644:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3117.548527] LustreError: 84644:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 3117.556754] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 3117.562066] Lustre: Skipped 1 previous similar message [ 3117.918106] Lustre: *** cfs_fail_loc=1311, val=0*** [ 3117.951729] Lustre: lustre-MDT0000: Aborting client recovery [ 3117.955479] LustreError: 84634:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3117.962060] Lustre: 84680:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3117.968729] Lustre: 84680:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3117.973879] Lustre: 84680:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 554b761e-e6ad-477b-bb92-ebd389a807c6@ [ 3117.983993] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3118.108890] Lustre: lustre-MDT0000-osd: cancel update llog [0x200015bc0:0x1:0x0] [ 3118.316168] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1516 to 0x280000400:1537) [ 3118.318984] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1516 to 0x240000400:1537) [ 3124.709962] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3131.512614] Lustre: *** cfs_fail_loc=1311, val=0*** [ 3139.541330] Lustre: DEBUG MARKER: == replay-single test 34: abort recovery before client does replay (test mds_cleanup_orphans) ========================================================== 12:55:21 (1788800121) [ 3144.541442] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3146.824387] Lustre: Failing over lustre-MDT0000 [ 3147.199852] Lustre: server umount lustre-MDT0000 complete [ 3158.073801] 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 [ 3158.087289] Lustre: Skipped 20 previous similar messages [ 3158.411934] Lustre: lustre-MDT0000: Aborting client recovery [ 3158.415571] LustreError: 86001:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3158.423759] Lustre: 86049:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3158.429760] Lustre: 86049:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3158.440966] Lustre: 86049:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 554b761e-e6ad-477b-bb92-ebd389a807c6@ [ 3158.455336] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3158.566950] Lustre: lustre-MDT0000-osd: cancel update llog [0x200016778:0x1:0x0] [ 3158.718890] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1543 to 0x280000400:1569) [ 3158.732035] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1544 to 0x240000400:1569) [ 3164.132634] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3178.471909] Lustre: DEBUG MARKER: == replay-single test 35: test recovery from llog for unlink op ========================================================== 12:55:59 (1788800159) [ 3179.738862] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3179.741819] LustreError: 86013:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9892ae8bb480 x1875689677584640/t201863462916(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:568/0 lens 512/456 e 0 to 0 dl 1788800173 ref 1 fl Interpret:/200/0 rc 0/0 job:'rm.0' uid:0 gid:0 projid:4294967295 [ 3184.119828] Lustre: Failing over lustre-MDT0000 [ 3184.532239] Lustre: server umount lustre-MDT0000 complete [ 3193.289620] Lustre: lustre-MDT0000: Aborting client recovery [ 3193.291353] LustreError: 87227:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3193.295788] Lustre: 87273:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3193.301547] Lustre: 87273:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3193.305070] Lustre: 87273:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 554b761e-e6ad-477b-bb92-ebd389a807c6@ [ 3193.310942] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3193.358985] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017330:0x1:0x0] [ 3193.486237] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1543 to 0x280000400:1601) [ 3193.504542] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1571 to 0x240000400:1601) [ 3198.165752] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3198.450464] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3198.464197] Lustre: Skipped 24 previous similar messages [ 3211.216983] Lustre: DEBUG MARKER: SKIP: replay-single test_36 skipping ALWAYS excluded test 36 [ 3212.879349] Lustre: DEBUG MARKER: == replay-single test 37: abort recovery before client does replay (test mds_cleanup_orphans for directories) ========================================================== 12:56:34 (1788800194) [ 3216.274156] LustreError: 88024:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 3216.279955] LustreError: 88024:0:(osd_handler.c:720:osd_ro()) Skipped 10 previous similar messages [ 3217.143691] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3219.863887] Lustre: Failing over lustre-MDT0000 [ 3220.176862] Lustre: server umount lustre-MDT0000 complete [ 3229.344545] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3229.351565] LustreError: Skipped 11 previous similar messages [ 3230.033916] Lustre: lustre-MDT0000: Aborting client recovery [ 3230.038657] LustreError: 88692:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3230.045701] Lustre: 88738:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3230.052693] Lustre: 88738:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3230.060957] Lustre: 88738:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 554b761e-e6ad-477b-bb92-ebd389a807c6@ [ 3230.078981] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3230.128614] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017b00:0x1:0x0] [ 3230.299491] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1571 to 0x240000400:1633) [ 3230.301387] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1543 to 0x280000400:1633) [ 3234.911781] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3248.622791] Lustre: DEBUG MARKER: == replay-single test 38: test recovery from unlink llog (test llog_gen_rec) ========================================================== 12:57:09 (1788800229) [ 3296.984747] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3298.907799] Lustre: Failing over lustre-MDT0000 [ 3299.170399] Lustre: server umount lustre-MDT0000 complete [ 3327.463287] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b775874ed [ 3328.506580] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3328.514321] Lustre: Skipped 8 previous similar messages [ 3328.603500] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3328.616091] Lustre: Skipped 8 previous similar messages [ 3328.634781] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2034 to 0x280000400:2049) [ 3328.635312] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2034 to 0x240000400:2049) [ 3332.774547] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3341.278122] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3342.562847] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3367.725623] Lustre: DEBUG MARKER: == replay-single test 39: test recovery from unlink llog (test llog_gen_rec) ========================================================== 12:59:09 (1788800349) [ 3393.658955] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3406.802540] Lustre: Failing over lustre-MDT0000 [ 3407.451434] Lustre: server umount lustre-MDT0000 complete [ 3441.174304] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3443.183803] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2450 to 0x240000400:2465) [ 3443.195120] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2450 to 0x280000400:2465) [ 3451.650117] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3453.663391] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3479.299258] Lustre: DEBUG MARKER: == replay-single test 41: read from a valid osc while other oscs are invalid ========================================================== 13:01:00 (1788800460) [ 3482.258129] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 3483.404376] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3483.409561] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 3490.652224] Lustre: DEBUG MARKER: == replay-single test 42: recovery after ost failure ===== 13:01:12 (1788800472) [ 3516.802684] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 3530.819559] Lustre: Failing over lustre-OST0000 [ 3530.981828] Lustre: server umount lustre-OST0000 complete [ 3532.269146] LustreError: 36637:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3534.341282] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3537.379694] LustreError: 36639:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3542.497236] LustreError: 36631:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3542.529511] LustreError: 36631:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 3550.654606] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3550.667316] Lustre: Skipped 20 previous similar messages [ 3556.667589] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3618.464664] Lustre: DEBUG MARKER: == replay-single test 43: mds osc import failure during recovery; don't LBUG ========================================================== 13:03:19 (1788800599) [ 3623.819956] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3627.439395] Lustre: Failing over lustre-MDT0000 [ 3627.491218] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3627.817319] Lustre: server umount lustre-MDT0000 complete [ 3654.550202] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3657.331319] Lustre: *** cfs_fail_loc=204, val=2147483648*** [ 3657.333334] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2913) [ 3665.070267] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3666.911568] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3673.568203] Lustre: 96779:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788800640/real 1788800640] req@ffff9892ae8b8e00 x1875689704111872/t0(0) o5->lustre-OST0001-osc-MDT0000@0@lo:28/4 lens 432/432 e 0 to 1 dl 1788800656 ref 2 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'osp-pre-1-0.0' uid:0 gid:0 projid:4294967295 [ 3673.587995] Lustre: 96779:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 43 previous similar messages [ 3673.596675] LustreError: 96779:0:(osp_precreate.c:974:osp_precreate_cleanup_orphans()) lustre-OST0001-osc-MDT0000: cannot cleanup orphans: rc = -11 [ 3673.599639] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3674.659465] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2881) [ 3687.087909] Lustre: DEBUG MARKER: == replay-single test 44a: race in target handle connect ========================================================== 13:04:28 (1788800668) [ 3693.035027] LustreError: 97403:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 3698.148110] LustreError: 97403:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3698.160587] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 3698.235861] LustreError: 36633:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 waking [ 3700.483687] LustreError: 97403:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 3705.824176] LustreError: 97403:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3705.832091] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 3707.674498] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 3712.992464] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3713.007652] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 3715.394967] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 3720.678163] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3722.986898] LustreError: 98171:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 3728.352177] LustreError: 98171:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3728.357641] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 3728.363652] Lustre: Skipped 1 previous similar message [ 3738.557094] LustreError: 98171:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 3738.562765] LustreError: 98171:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 1 previous similar message [ 3743.716395] LustreError: 98171:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3743.727548] LustreError: 98171:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 1 previous similar message [ 3751.393317] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 3751.415782] Lustre: Skipped 2 previous similar messages [ 3761.659093] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 3761.667254] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 2 previous similar messages [ 3766.753326] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 3766.765534] LustreError: 96754:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 2 previous similar messages [ 3778.673078] Lustre: DEBUG MARKER: == replay-single test 44b: race in target handle connect ========================================================== 13:05:59 (1788800759) [ 3781.423946] LustreError: 98171:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3791.365503] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3795.403689] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3800.568899] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3804.830414] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3810.808593] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3810.818401] Lustre: Skipped 1 previous similar message [ 3821.051611] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3821.073160] Lustre: Skipped 1 previous similar message [ 3821.512939] LustreError: 98171:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3821.533785] Lustre: 98171:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff9892bb73b800 x1875689680229888/t0(0) o38->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:0/0 lens 520/416 e 0 to 0 dl 1788800784 ref 1 fl Complete:H/200/0 rc 0/0 job:'lctl.0' uid:0 gid:0 projid:4294967295 [ 3826.169081] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 3826.189107] Lustre: Skipped 3 previous similar messages [ 3826.204051] LustreError: 97403:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3851.768150] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3866.272204] LustreError: 97403:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3866.283557] Lustre: 97403:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/21s); client may timeout req@ffff9892baaead80 x1875689680233088/t0(0) o38->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:0/0 lens 520/416 e 0 to 0 dl 1788800828 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3867.123948] LustreError: 96755:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3892.728478] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3892.738862] Lustre: Skipped 2 previous similar messages [ 3907.136445] LustreError: 96755:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3907.146835] Lustre: 96755:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff9892b6988a80 x1875689680234752/t0(0) o38->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:0/0 lens 520/416 e 0 to 0 dl 1788800869 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3907.586469] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 3907.607534] Lustre: Skipped 1 previous similar message [ 3907.618397] LustreError: 96756:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3947.656670] LustreError: 96756:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3947.671187] Lustre: 96756:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff98929768aa00 x1875689680236544/t0(0) o38->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:0/0 lens 520/416 e 0 to 0 dl 1788800910 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3952.631489] LustreError: 96754:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 3977.205054] Lustre: lustre-MDT0000: Export ffff989283fc1800 already connecting from 192.168.204.50@tcp [ 3977.213851] Lustre: Skipped 7 previous similar messages [ 3992.680124] LustreError: 96754:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 3992.694594] Lustre: 96754:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff989282f85500 x1875689680238720/t0(0) o38->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:0/0 lens 520/416 e 0 to 0 dl 1788800955 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3997.690950] LustreError: 96755:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4012.145417] LustreError: 96755:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout interrupted [ 4018.121426] Lustre: DEBUG MARKER: == replay-single test 44c: race in target handle connect ========================================================== 13:09:59 (1788800999) [ 4022.316162] LustreError: 100614:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 4022.326705] LustreError: 100614:0:(osd_handler.c:720:osd_ro()) Skipped 4 previous similar messages [ 4023.676755] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4029.204550] Lustre: Failing over lustre-MDT0000 [ 4029.693516] Lustre: server umount lustre-MDT0000 complete [ 4041.216327] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4041.229847] LustreError: Skipped 3 previous similar messages [ 4041.757365] Lustre: *** cfs_fail_loc=712, val=0*** [ 4041.777593] 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 [ 4041.787115] LustreError: 36639:0:(service.c:1394:ptlrpc_check_req()) @@@ Invalid replay without recovery req@ffff9892b7199180 x1875689704185344/t0(0) o400->lustre-MDT0000-mdtlov_UUID@0@lo:0/0 lens 224/0 e 0 to 0 dl 0 ref 1 fl New:/2c0/ffffffff rc 0/-1 job:'ptlrpcd_rcv.0' uid:0 gid:0 projid:4294967295 [ 4041.803400] Lustre: Skipped 13 previous similar messages [ 4042.057665] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4042.061662] Lustre: Skipped 8 previous similar messages [ 4042.137412] Lustre: lustre-MDT0000: Aborting client recovery [ 4042.141121] LustreError: 101283:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 4042.146226] Lustre: 101332:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4042.151020] Lustre: 101332:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 4042.159125] Lustre: 101332:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 554b761e-e6ad-477b-bb92-ebd389a807c6@ [ 4042.169552] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 4042.218587] Lustre: lustre-MDT0000-osd: cancel update llog [0x2000182d0:0x1:0x0] [ 4042.377168] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2913) [ 4042.382192] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2945) [ 4047.338910] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4047.348323] Lustre: Skipped 13 previous similar messages [ 4048.532940] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4058.801808] Lustre: Failing over lustre-MDT0000 [ 4059.155727] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.50@tcp (stopping) [ 4059.166567] Lustre: Skipped 1 previous similar message [ 4059.421689] Lustre: server umount lustre-MDT0000 complete [ 4088.289029] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892b6ccce00 x1875689704197376/t0(0) o250->MGC192.168.204.150@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 [ 4088.306550] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) Skipped 4 previous similar messages [ 4094.170908] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4099.074727] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4099.087370] Lustre: Skipped 3 previous similar messages [ 4099.226143] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4099.244562] Lustre: Skipped 3 previous similar messages [ 4099.309452] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2945) [ 4099.312574] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2977) [ 4107.104747] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4109.226577] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4120.222334] Lustre: DEBUG MARKER: == replay-single test 45: Handle failed close ============ 13:11:41 (1788801101) [ 4120.440255] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 4120.450990] Lustre: Skipped 2 previous similar messages [ 4131.331534] Lustre: DEBUG MARKER: == replay-single test 46: Don't leak file handle after open resend (3325) ========================================================== 13:11:52 (1788801112) [ 4133.250655] Lustre: *** cfs_fail_loc=122, val=2147483648*** [ 4133.252847] LustreError: 102265:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff989182269c00 x1875689680296832/t0(0) o700->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:11/0 lens 264/248 e 0 to 0 dl 1788801126 ref 1 fl Interpret:/200/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:4294967295 [ 4153.815510] Lustre: Failing over lustre-MDT0000 [ 4154.133419] Lustre: server umount lustre-MDT0000 complete [ 4181.986275] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b775bc2dc [ 4182.640539] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4182.649537] Lustre: Skipped 5 previous similar messages [ 4187.781442] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4195.999922] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2979 to 0x240000400:3009) [ 4196.001610] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2947 to 0x280000400:2977) [ 4203.016636] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4205.571353] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4218.058654] Lustre: DEBUG MARKER: == replay-single test 47: MDS->OSC failure during precreate cleanup (2824) ========================================================== 13:13:19 (1788801199) [ 4221.610120] Lustre: Failing over lustre-OST0000 [ 4221.727463] Lustre: server umount lustre-OST0000 complete [ 4221.922849] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 4221.940046] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4221.966435] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [ 4226.552971] LustreError: 36640:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4226.575649] LustreError: 36640:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 4231.666791] LustreError: 36633:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4231.687739] LustreError: 36633:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 4236.794574] LustreError: 6705:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4236.819173] LustreError: 6705:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 4249.658127] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4261.333338] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 4263.052525] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 4338.315779] Lustre: DEBUG MARKER: == replay-single test 48: MDS->OSC failure during precreate cleanup (2824) ========================================================== 13:15:19 (1788801319) [ 4343.636521] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4347.132636] Lustre: Failing over lustre-MDT0000 [ 4347.668760] Lustre: server umount lustre-MDT0000 complete [ 4365.734223] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788801332/real 1788801332] req@ffff9891810f8a80 x1875689704264832/t0(0) o400->MGC192.168.204.150@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1788801348 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4365.770111] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 22 previous similar messages [ 4381.899057] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4391.105428] Lustre: *** cfs_fail_loc=216, val=0*** [ 4391.107389] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2998 to 0x280000400:3041) [ 4391.108608] LustreError: 107132:0:(osp_precreate.c:974:osp_precreate_cleanup_orphans()) lustre-OST0000-osc-MDT0000: cannot cleanup orphans: rc = -30 [ 4392.167558] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3030 to 0x240000400:3073) [ 4461.196605] Lustre: DEBUG MARKER: == replay-single test 50: Double OSC recovery, don't LASSERT (3812) ========================================================== 13:17:22 (1788801442) [ 4463.770662] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 4463.785066] Lustre: Skipped 2 previous similar messages [ 4479.401676] Lustre: DEBUG MARKER: == replay-single test 52: time out lock replay (3764) ==== 13:17:40 (1788801460) [ 4483.590320] Lustre: Failing over lustre-MDT0000 [ 4484.203169] Lustre: server umount lustre-MDT0000 complete [ 4513.442392] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b775bea2e [ 4519.316380] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4528.656147] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 4528.659465] LustreError: 108812:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff98928fc61180 x1875689680418048/t0(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:407/0 lens 328/344 e 0 to 0 dl 1788801522 ref 1 fl Complete:/240/0 rc 0/0 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 4543.996375] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnected, waiting for 1 clients in recovery for 1:25 [ 4544.155891] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3052 to 0x280000400:3073) [ 4544.157153] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3085 to 0x240000400:3105) [ 4552.653207] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4554.317996] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4566.214880] Lustre: DEBUG MARKER: == replay-single test 53a: |X| close request while two MDC requests in flight ========================================================== 13:19:07 (1788801547) [ 4568.816558] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4574.635486] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4576.963874] Lustre: Failing over lustre-MDT0000 [ 4577.312034] Lustre: server umount lustre-MDT0000 complete [ 4606.440471] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b775bee48 [ 4611.535092] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3052 to 0x280000400:3105) [ 4611.536925] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3107 to 0x240000400:3137) [ 4612.646952] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4623.777401] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4625.631371] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4634.892567] Lustre: DEBUG MARKER: == replay-single test 53b: |X| open request while two MDC requests in flight ========================================================== 13:20:16 (1788801616) [ 4636.186924] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 4641.469031] LustreError: 111622:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 4641.475214] LustreError: 111622:0:(osd_handler.c:720:osd_ro()) Skipped 2 previous similar messages [ 4642.346592] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4644.385990] Lustre: Failing over lustre-MDT0000 [ 4644.676372] Lustre: server umount lustre-MDT0000 complete [ 4663.264771] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4663.264808] 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 [ 4663.264830] LustreError: Skipped 5 previous similar messages [ 4663.312915] Lustre: Skipped 14 previous similar messages [ 4674.479876] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4674.486373] Lustre: Skipped 6 previous similar messages [ 4678.058926] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3107 to 0x280000400:3137) [ 4678.061686] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3107 to 0x240000400:3169) [ 4680.425965] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4688.499930] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4688.515424] Lustre: Skipped 17 previous similar messages [ 4691.028814] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4692.874586] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4703.494747] Lustre: DEBUG MARKER: == replay-single test 53c: |X| open request and close request while two MDC requests in flight ========================================================== 13:21:24 (1788801684) [ 4704.803966] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 4706.995244] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4711.206435] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4713.346879] Lustre: Failing over lustre-MDT0000 [ 4713.661562] Lustre: server umount lustre-MDT0000 complete [ 4741.091065] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892baae9f80 x1875689704361088/t0(0) o250->MGC192.168.204.150@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 [ 4741.120869] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) Skipped 2 previous similar messages [ 4745.740415] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4745.747044] Lustre: Skipped 6 previous similar messages [ 4745.875193] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4745.892176] Lustre: Skipped 6 previous similar messages [ 4745.948380] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3107 to 0x240000400:3201) [ 4745.948649] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3139 to 0x280000400:3169) [ 4746.738201] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4759.004889] Lustre: DEBUG MARKER: == replay-single test 53d: close reply while two MDC requests in flight ========================================================== 13:22:20 (1788801740) [ 4761.514396] Lustre: *** cfs_fail_loc=13b, val=315*** [ 4761.525420] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 4761.534635] LustreError: 113930:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff98929767ad80 x1875689680466688/t257698037777(0) o35->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:640/0 lens 392/456 e 0 to 0 dl 1788801755 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 4764.518869] Lustre: Failing over lustre-MDT0000 [ 4765.073307] Lustre: server umount lustre-MDT0000 complete [ 4792.796953] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4792.810991] Lustre: Skipped 6 previous similar messages [ 4798.962969] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4802.200360] Lustre: 115228:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9892a0016300 x1875689680466688/t257698037777(0) o35->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:680/0 lens 392/456 e 0 to 0 dl 1788801795 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 4802.219698] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3203 to 0x240000400:3233) [ 4802.220327] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3139 to 0x280000400:3201) [ 4808.801765] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4810.705371] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4820.892753] Lustre: DEBUG MARKER: == replay-single test 53e: |X| open reply while two MDC requests in flight ========================================================== 13:23:22 (1788801802) [ 4822.745946] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4822.750369] LustreError: 115227:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff989297698380 x1875689680480768/t261993005072(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:701/0 lens 504/448 e 0 to 0 dl 1788801816 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4829.143908] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4831.684552] Lustre: Failing over lustre-MDT0000 [ 4832.158940] Lustre: server umount lustre-MDT0000 complete [ 4863.795770] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4864.486238] Lustre: 116921:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9892974d4a80 x1875689680480768/t261993005072(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:743/0 lens 504/2880 e 0 to 0 dl 1788801858 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4864.508771] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3235 to 0x240000400:3265) [ 4864.508771] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3139 to 0x280000400:3233) [ 4873.719047] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4875.513789] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4885.886413] Lustre: DEBUG MARKER: == replay-single test 53f: |X| open reply and close reply while two MDC requests in flight ========================================================== 13:24:27 (1788801867) [ 4886.984632] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4886.988209] LustreError: 117572:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9891810f9880 x1875689680495104/t266287972368(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:10/0 lens 504/448 e 0 to 0 dl 1788801880 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4889.136084] Lustre: *** cfs_fail_loc=13b, val=315*** [ 4893.455334] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4895.526144] Lustre: Failing over lustre-MDT0000 [ 4895.879723] Lustre: server umount lustre-MDT0000 complete [ 4928.171465] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3235 to 0x240000400:3297) [ 4928.172234] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3235 to 0x280000400:3265) [ 4928.187552] Lustre: 118628:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff989298886680 x1875689680495104/t266287972368(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:51/0 lens 504/2880 e 0 to 0 dl 1788801921 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4928.234246] Lustre: 118628:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 1 previous similar message [ 4930.138535] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4942.067478] Lustre: DEBUG MARKER: == replay-single test 53g: |X| drop open reply and close request while close and open are both in flight ========================================================== 13:25:23 (1788801923) [ 4943.285629] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 4943.293488] Lustre: Skipped 1 previous similar message [ 4943.295313] LustreError: 118627:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9892c0357480 x1875689680507904/t270582939664(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:67/0 lens 504/448 e 0 to 0 dl 1788801937 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4943.313521] LustreError: 118627:0:(ldlm_lib.c:3382:target_send_reply_msg()) Skipped 1 previous similar message [ 4945.232788] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4950.062260] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4952.200602] Lustre: Failing over lustre-MDT0000 [ 4952.458169] Lustre: server umount lustre-MDT0000 complete [ 4970.336132] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788801937/real 1788801937] req@ffff98929767bb80 x1875689704424064/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788801953 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4970.358983] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 74 previous similar messages [ 4980.579495] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b775c11c6 [ 4984.585296] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3299 to 0x240000400:3329) [ 4984.590517] Lustre: 120166:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff989298884380 x1875689680507904/t270582939664(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:108/0 lens 504/2880 e 0 to 0 dl 1788801978 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 4984.591242] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3235 to 0x280000400:3297) [ 4986.349427] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4998.136453] Lustre: DEBUG MARKER: == replay-single test 53h: open request and close reply while two MDC requests in flight ========================================================== 13:26:19 (1788801979) [ 4999.576524] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 5001.530236] Lustre: *** cfs_fail_loc=13b, val=315*** [ 5001.541292] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 5001.547499] LustreError: 120169:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9892baae8700 x1875689680521088/t274877906960(0) o35->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:125/0 lens 392/456 e 0 to 0 dl 1788801995 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5006.880204] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5009.532155] Lustre: Failing over lustre-MDT0000 [ 5009.814216] Lustre: server umount lustre-MDT0000 complete [ 5036.451164] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b775c17a0 [ 5041.728630] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3331 to 0x240000400:3361) [ 5041.729449] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3235 to 0x280000400:3329) [ 5041.804108] Lustre: 121626:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff989297688e00 x1875689680521088/t274877906960(0) o35->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:165/0 lens 392/456 e 0 to 0 dl 1788802035 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5042.514458] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5055.443588] Lustre: DEBUG MARKER: == replay-single test 55: let MDS_CHECK_RESENT return the original return code instead of 0 ========================================================== 13:27:16 (1788802036) [ 5056.578707] Lustre: *** cfs_fail_loc=12b, val=2147483991*** [ 5056.584596] LustreError: 121625:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9892a049c000 x1875689680531328/t279172874255(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:180/0 lens 664/608 e 0 to 0 dl 1788802050 ref 1 fl Interpret:/600/0 rc 301/0 job:'touch.0' uid:0 gid:0 projid:0 [ 5072.915218] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnecting [ 5072.928682] Lustre: Skipped 1 previous similar message [ 5072.946410] Lustre: 121624:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9892974d4380 x1875689680531328/t279172874255(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:196/0 lens 664/3488 e 0 to 0 dl 1788802066 ref 1 fl Interpret:/602/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:0 [ 5082.164565] Lustre: DEBUG MARKER: == replay-single test 56: don't replay a symlink open request (3440) ========================================================== 13:27:43 (1788802063) [ 5086.618268] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5089.936950] Lustre: Failing over lustre-MDT0000 [ 5090.372348] Lustre: server umount lustre-MDT0000 complete [ 5117.389961] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5119.142383] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3331 to 0x240000400:3393) [ 5119.144538] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3331 to 0x280000400:3361) [ 5129.859233] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5132.412347] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5152.562742] Lustre: DEBUG MARKER: == replay-single test 57: test recovery from llog for setattr op ========================================================== 13:28:53 (1788802133) [ 5158.367529] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5160.900929] Lustre: Failing over lustre-MDT0000 [ 5160.944496] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5161.355662] Lustre: server umount lustre-MDT0000 complete [ 5191.676413] LustreError: 125006:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5191.710327] LustreError: 125006:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 5193.359713] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3331 to 0x280000400:3393) [ 5193.361907] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3395 to 0x240000400:3425) [ 5196.981452] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5207.839511] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5209.536651] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5216.012264] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 5229.931578] Lustre: DEBUG MARKER: == replay-single test 58a: test recovery from llog for setattr op (test llog_gen_rec) ========================================================== 13:30:11 (1788802211) [ 5278.602978] LustreError: 126586:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5278.621766] LustreError: 126586:0:(osd_handler.c:720:osd_ro()) Skipped 7 previous similar messages [ 5279.792662] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5282.249177] Lustre: Failing over lustre-MDT0000 [ 5282.288488] 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 [ 5282.314737] Lustre: Skipped 18 previous similar messages [ 5282.830369] Lustre: server umount lustre-MDT0000 complete [ 5302.682106] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5302.708497] LustreError: Skipped 8 previous similar messages [ 5303.244345] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5303.250504] Lustre: Skipped 8 previous similar messages [ 5304.174597] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5304.183803] Lustre: Skipped 19 previous similar messages [ 5308.263648] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5309.851673] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4676 to 0x240000400:4705) [ 5309.852572] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4644 to 0x280000400:4673) [ 5319.687531] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5321.625617] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5393.744927] Lustre: DEBUG MARKER: == replay-single test 58b: test replay of setxattr op ==== 13:32:55 (1788802375) [ 5399.142857] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5401.638796] Lustre: Failing over lustre-MDT0000 [ 5402.005585] Lustre: server umount lustre-MDT0000 complete [ 5422.054237] LustreError: 129054:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5422.712471] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5422.720549] Lustre: Skipped 7 previous similar messages [ 5423.731371] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5423.737439] Lustre: Skipped 8 previous similar messages [ 5427.712168] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5431.096371] Lustre: lustre-MDT0000: Recovery over after 0:08, of 2 clients 2 recovered and 0 were evicted. [ 5431.107244] Lustre: Skipped 8 previous similar messages [ 5431.178293] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4675 to 0x280000400:4705) [ 5431.183704] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4676 to 0x240000400:4737) [ 5438.359354] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5440.756749] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5451.069117] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount FULL mgc.*.mgs_server_uuid 1475 0 [ 5452.661174] Lustre: DEBUG MARKER: mgc.*.mgs_server_uuid in FULL state after 0 sec [ 5461.150694] Lustre: DEBUG MARKER: == replay-single test 58c: resend/reconstruct setxattr op ========================================================== 13:34:02 (1788802442) [ 5468.334341] Lustre: *** cfs_fail_loc=123, val=2147483648*** [ 5487.447186] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 5487.452389] Lustre: Skipped 1 previous similar message [ 5487.455588] LustreError: 129056:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9891897e9050 x1875689683317248/t296352743435(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:611/0 lens 66040/440 e 0 to 0 dl 1788802481 ref 1 fl Interpret:/600/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 5502.972988] Lustre: 129055:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9892bab49180 x1875689683317248/t296352743435(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:626/0 lens 66040/440 e 0 to 0 dl 1788802496 ref 1 fl Interpret:/602/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 5515.035931] Lustre: DEBUG MARKER: SKIP: replay-single test_59 skipping ALWAYS excluded test 59 [ 5517.259159] Lustre: DEBUG MARKER: == replay-single test 60: test llog post recovery init vs llog unlink ========================================================== 13:34:58 (1788802498) [ 5531.169956] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5534.463324] Lustre: Failing over lustre-MDT0000 [ 5534.571279] LustreError: 3316:0:(client.c:1394:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff9892b6988380 x1875689705221120/t0(0) o6->lustre-OST0001-osc-MDT0000@0@lo:28/4 lens 544/432 e 0 to 0 dl 0 ref 1 fl Rpc:QU/200/ffffffff rc 0/-1 job:'osp-syn-1-0.0' uid:0 gid:0 projid:4294967295 [ 5534.891087] Lustre: server umount lustre-MDT0000 complete [ 5560.806169] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9892974d4a80 x1875689705223424/t0(0) o250->MGC192.168.204.150@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 [ 5560.841454] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) Skipped 12 previous similar messages [ 5565.814376] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4806 to 0x280000400:4833) [ 5565.863604] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4839 to 0x240000400:4865) [ 5566.879456] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5578.517981] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5580.778117] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5592.469314] Lustre: DEBUG MARKER: == replay-single test 61a: test race llog recovery vs llog cleanup ========================================================== 13:36:13 (1788802573) [ 5617.663164] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 5634.799293] Lustre: Failing over lustre-OST0000 [ 5635.007961] Lustre: server umount lustre-OST0000 complete [ 5637.617867] LustreError: 36639:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5637.633430] LustreError: 36639:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 5642.734883] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5652.971176] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5652.987462] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 5663.063734] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5678.692613] Lustre: Failing over lustre-OST0000 [ 5678.710063] LustreError: 134100:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-OST0000: Aborting recovery [ 5678.716958] Lustre: 133534:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 5678.723289] Lustre: 133534:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 5678.729769] Lustre: 133534:0:(ldlm_lib.c:1948:abort_req_replay_queue()) @@@ aborted: req@ffff9891810f9880 x1875689705270784/t0(17179870646) o6->lustre-MDT0000-mdtlov_UUID@0@lo:50/0 lens 544/0 e 2 to 0 dl 1788802675 ref 1 fl Complete:/204/ffffffff rc 0/-1 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 5678.756859] LustreError: 133534:0:(ofd_obd.c:1325:ofd_iocontrol()) lustre-OST0000: iocontrol from 'tgt_recover_0' cmd=c00866c1 _IOWR('f', 193, 8) unrecognized: rc = -25 [ 5678.760261] LustreError: lustre-OST0000-osc-MDT0000: operation ost_destroy to node 0@lo failed: rc = -19 [ 5678.854368] Lustre: server umount lustre-OST0000 complete [ 5684.194157] LustreError: 36631:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5705.975762] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5710.726889] LustreError: 3312:0:(client.c:3449:ptlrpc_replay_interpret()) @@@ status 0, old was -19 req@ffff989298887100 x1875689705270784/t17179870646(17179870646) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 3 to 0 dl 1788802710 ref 2 fl Interpret:RQU/204/0 rc 0/0 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 5719.910321] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 5722.315534] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5766.379753] Lustre: DEBUG MARKER: == replay-single test 61b: test race mds llog sync vs llog cleanup ========================================================== 13:39:07 (1788802747) [ 5770.190345] Lustre: Failing over lustre-MDT0000 [ 5770.600039] Lustre: server umount lustre-MDT0000 complete [ 5786.912920] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788802753/real 1788802753] req@ffff989186caf480 x1875689705408512/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788802769 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5786.958716] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 40 previous similar messages [ 5798.918582] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5801.134689] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5281) [ 5801.139353] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5249) [ 5814.857043] Lustre: Failing over lustre-MDT0000 [ 5815.281631] Lustre: server umount lustre-MDT0000 complete [ 5849.899713] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5857.430941] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5281) [ 5857.431267] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5313) [ 5865.641447] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5867.651665] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5879.295087] Lustre: DEBUG MARKER: == replay-single test 61c: test race mds llog sync vs llog cleanup ========================================================== 13:40:59 (1788802859) [ 5895.947345] Lustre: Failing over lustre-OST0000 [ 5898.146075] Lustre: server umount lustre-OST0000 complete [ 5898.250118] LustreError: 36639:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5898.277969] LustreError: 36639:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 2 previous similar messages [ 5898.732923] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 5898.742923] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5898.755333] Lustre: Skipped 9 previous similar messages [ 5918.082608] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5918.099248] Lustre: Skipped 6 previous similar messages [ 5919.388654] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 5919.399759] Lustre: Skipped 10 previous similar messages [ 5925.853523] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5937.171296] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 5939.923448] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5950.878455] Lustre: DEBUG MARKER: == replay-single test 61d: error in llog_setup should cleanup the llog context correctly ========================================================== 13:42:12 (1788802932) [ 5953.085213] Lustre: Failing over lustre-MDT0000 [ 5953.437539] Lustre: server umount lustre-MDT0000 complete [ 5965.162320] Lustre: *** cfs_fail_loc=605, val=0*** [ 5965.166496] LustreError: 140123:0:(llog_obd.c:192:llog_setup()) MGS: ctxt 0 lop_setup=ffffffffc12bf340 failed: rc = -95 [ 5965.174322] LustreError: 140123:0:(obd_config.c:845:class_setup()) setup MGS failed (-95) [ 5965.183818] LustreError: 140123:0:(obd_mount.c:259:lustre_start_simple()) MGS setup error -95 [ 5965.188797] LustreError: 140123:0:(tgt_mount.c:116:server_deregister_mount()) MGS not registered [ 5965.198966] LustreError: Failed to start MGS 'MGS' (-95). Is the 'mgs' module loaded? [ 5965.205477] LustreError: 140123:0:(tgt_mount.c:2128:server_put_super()) no obd lustre-MDT0000 [ 5965.315612] Lustre: server umount lustre-MDT0000 complete [ 5965.323702] LustreError: 140123:0:(super25.c:179:lustre_fill_super()) llite: Unable to mount : rc = -95 [ 5969.376563] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5969.389700] LustreError: Skipped 4 previous similar messages [ 5981.380533] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5315 to 0x240000400:5345) [ 5981.386513] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5283 to 0x280000400:5313) [ 5985.406251] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5994.843584] Lustre: DEBUG MARKER: == replay-single test 62: don't mis-drop resent replay === 13:42:55 (1788802975) [ 5998.210340] LustreError: 141180:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5998.219585] LustreError: 141180:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 5999.284411] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6002.959839] Lustre: Failing over lustre-MDT0000 [ 6003.391652] Lustre: server umount lustre-MDT0000 complete [ 6030.329839] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b77617a30 [ 6030.956755] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 6030.968099] Lustre: Skipped 7 previous similar messages [ 6032.373694] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 6032.389720] Lustre: Skipped 7 previous similar messages [ 6032.444731] Lustre: *** cfs_fail_loc=707, val=0*** [ 6037.601741] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6048.771972] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 6049.448178] Lustre: lustre-MDT0000: Recovery over after 0:17, of 1 clients 1 recovered and 0 were evicted. [ 6049.470525] Lustre: Skipped 7 previous similar messages [ 6049.529091] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5358 to 0x240000400:5377) [ 6049.530259] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5327 to 0x280000400:5345) [ 6056.859555] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 6058.743210] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6071.048910] Lustre: DEBUG MARKER: == replay-single test 65a: AT: verify early replies ====== 13:44:12 (1788803052) [ 6105.584444] LustreError: 142495:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff9891855dd880 x1875689684194688/t0(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:474/0 lens 664/0 e 0 to 0 dl 1788803099 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6105.618859] LustreError: 142495:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 11000ms [ 6116.702147] LustreError: 142495:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6116.735828] LustreError: 141849:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff9891861ec380 x1875689684195456/t0(0) o35->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:491/0 lens 392/0 e 0 to 0 dl 1788803116 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6119.099409] LustreError: 142495:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff98918666bb80 x1875689684201344/t0(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:526/0 lens 576/0 e 0 to 0 dl 1788803151 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'unlinkmany.0' uid:0 gid:0 projid:0 [ 6119.136884] LustreError: 142495:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 27 previous similar messages [ 6126.065858] LustreError: 36639:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff98929769aa00 x1875689705501056/t0(0) o6->lustre-MDT0000-mdtlov_UUID@0@lo:494/0 lens 544/0 e 0 to 0 dl 1788803119 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-syn-1-0.0' uid:0 gid:0 projid:4294967295 [ 6126.120797] LustreError: 36639:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 28 previous similar messages [ 6135.639332] Lustre: DEBUG MARKER: == replay-single test 65b: AT: verify early replies on packed reply / bulk ========================================================== 13:45:17 (1788803117) [ 6166.120366] LustreError: 6710:0:(tgt_handler.c:2830:tgt_brw_write()) cfs_fail_timeout id 224 sleeping for 11000ms [ 6177.152241] LustreError: 6710:0:(tgt_handler.c:2830:tgt_brw_write()) cfs_fail_timeout id 224 awake [ 6188.267994] Lustre: DEBUG MARKER: == replay-single test 66a: AT: verify MDT service time adjusts with no early replies ========================================================== 13:46:09 (1788803169) [ 6217.714593] LustreError: 141844:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff9892903c5180 x1875689684217344/t0(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:586/0 lens 576/0 e 0 to 0 dl 1788803211 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6217.733310] LustreError: 141844:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 5000ms [ 6222.760153] LustreError: 141844:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6225.843780] LustreError: 142495:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff9892a0562a00 x1875689684238208/t0(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:594/0 lens 576/0 e 0 to 0 dl 1788803219 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6225.879417] LustreError: 142495:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 101 previous similar messages [ 6225.895876] LustreError: 142495:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 10000ms [ 6235.904185] LustreError: 142495:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6255.579152] Lustre: DEBUG MARKER: == replay-single test 66b: AT: verify net latency adjusts ========================================================== 13:47:17 (1788803237) [ 6350.092487] Lustre: DEBUG MARKER: == replay-single test 67a: AT: verify slow request processing doesn't induce reconnects ========================================================== 13:48:51 (1788803331) [ 6379.937612] LustreError: 142495:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff9892a0c5f480 x1875689684291712/t0(0) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:748/0 lens 576/0 e 0 to 0 dl 1788803373 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6379.966384] LustreError: 142495:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 117 previous similar messages [ 6379.971655] LustreError: 142495:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 6380.392149] LustreError: 142495:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6396.704142] LustreError: 141849:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6396.715731] LustreError: 141849:0:(service.c:2564:ptlrpc_server_handle_request()) Skipped 37 previous similar messages [ 6412.121642] LustreError: 143259:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff9892bab49500 x1875689684309504/t0(0) o36->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:25/0 lens 504/0 e 0 to 0 dl 1788803405 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'unlinkmany.0' uid:0 gid:0 projid:4294967295 [ 6412.142285] LustreError: 143259:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 77 previous similar messages [ 6412.151416] LustreError: 143259:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 6412.158180] LustreError: 143259:0:(service.c:2564:ptlrpc_server_handle_request()) Skipped 77 previous similar messages [ 6431.108373] Lustre: DEBUG MARKER: == replay-single test 67b: AT: verify instant slowdown doesn't induce reconnects ========================================================== 13:50:12 (1788803412) [ 6465.669661] Lustre: DEBUG MARKER: phase 2 [ 6476.076310] Lustre: DEBUG MARKER: == replay-single test 68: AT: verify slowing locks ======= 13:50:57 (1788803457) [ 6559.909165] Lustre: DEBUG MARKER: == replay-single test 70a: check multi client t-f ======== 13:52:21 (1788803541) [ 6561.583570] Lustre: DEBUG MARKER: SKIP: replay-single test_70a Need two or more clients, have 1 [ 6563.781992] Lustre: DEBUG MARKER: == replay-single test 70b: dbench 1mdts recovery; 1 clients ========================================================== 13:52:25 (1788803545) [ 6568.228411] Lustre: DEBUG MARKER: Started rundbench load pid=128910 ... [ 6573.424585] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6575.933344] Lustre: DEBUG MARKER: test_70b fail mds1 1 times [ 6578.014957] Lustre: Failing over lustre-MDT0000 [ 6578.296294] Lustre: server umount lustre-MDT0000 complete [ 6594.784093] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788803561/real 1788803561] req@ffff989298887b80 x1875689705631104/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788803577 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6594.817076] Lustre: 3316:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 33 previous similar messages [ 6594.819704] 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 [ 6594.845594] Lustre: Skipped 4 previous similar messages [ 6596.036900] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6596.044918] LustreError: Skipped 1 previous similar message [ 6596.416341] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6596.420540] Lustre: Skipped 2 previous similar messages [ 6600.952607] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6604.514626] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 6604.523602] Lustre: Skipped 5 previous similar messages [ 6615.955096] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5424 to 0x280000400:5441) [ 6615.958173] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5478 to 0x240000400:5505) [ 6622.469113] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 6623.995584] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6630.309903] LustreError: 150127:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 6630.314657] LustreError: 150127:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 6631.403963] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6634.124971] Lustre: DEBUG MARKER: test_70b fail mds1 2 times [ 6636.034075] Lustre: Failing over lustre-MDT0000 [ 6636.480963] Lustre: server umount lustre-MDT0000 complete [ 6656.203043] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 6656.211693] Lustre: Skipped 1 previous similar message [ 6660.671870] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6674.995980] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 6675.006167] Lustre: Skipped 1 previous similar message [ 6675.815059] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 6675.826814] Lustre: Skipped 1 previous similar message [ 6675.883542] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5464 to 0x280000400:5505) [ 6675.883752] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5529 to 0x240000400:5569) [ 6682.061803] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 6683.857130] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6720.386147] Lustre: DEBUG MARKER: == replay-single test 70c: tar 1mdts recovery ============ 13:55:01 (1788803701) [ 6846.462607] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6859.031270] Lustre: DEBUG MARKER: test_70c fail mds1 1 times [ 6861.384287] Lustre: Failing over lustre-MDT0000 [ 6863.915203] Lustre: server umount lustre-MDT0000 complete [ 6897.199425] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6906.704533] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6200 to 0x280000400:6241) [ 6906.706256] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6264 to 0x240000400:6305) [ 6912.038959] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 6913.803330] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7013.919384] Lustre: DEBUG MARKER: == replay-single test 70d: mkdir/rmdir striped dir 1mdts recovery ========================================================== 13:59:55 (1788803995) [ 7015.133831] Lustre: DEBUG MARKER: SKIP: replay-single test_70d needs >= 2 MDTs [ 7016.798958] Lustre: DEBUG MARKER: == replay-single test 70e: rename cross-MDT with random fails ========================================================== 13:59:58 (1788803998) [ 7018.186769] Lustre: DEBUG MARKER: SKIP: replay-single test_70e needs >= 2 MDTs [ 7019.591802] Lustre: DEBUG MARKER: == replay-single test 70f: OSS O_DIRECT recovery with 1 clients ========================================================== 14:00:01 (1788804001) [ 7027.015831] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7029.426838] Lustre: DEBUG MARKER: test_70f failing OST 1 times [ 7031.367425] Lustre: Failing over lustre-OST0000 [ 7031.429153] Lustre: server umount lustre-OST0000 complete [ 7034.850175] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7034.869257] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7034.888607] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 8 previous similar messages [ 7045.602290] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7045.616095] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 4 previous similar messages [ 7056.972792] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7068.108752] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7070.079955] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7081.842522] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7084.804687] Lustre: DEBUG MARKER: test_70f failing OST 2 times [ 7087.476971] Lustre: Failing over lustre-OST0000 [ 7087.585340] Lustre: server umount lustre-OST0000 complete [ 7087.598516] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7087.634969] LustreError: 36631:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7087.659955] LustreError: 36631:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 7115.430488] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7125.749449] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7127.465404] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7138.988798] Lustre: DEBUG MARKER: == replay-single test 71a: mkdir/rmdir striped dir with 2 mdts recovery ========================================================== 14:02:00 (1788804120) [ 7140.748510] Lustre: DEBUG MARKER: SKIP: replay-single test_71a needs >= 2 MDTs [ 7142.563591] Lustre: DEBUG MARKER: == replay-single test 73a: open(O_CREAT), unlink, replay, reconnect before open replay, close ========================================================== 14:02:04 (1788804124) [ 7146.210813] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7148.883343] Lustre: Failing over lustre-MDT0000 [ 7149.130442] Lustre: server umount lustre-MDT0000 complete [ 7176.166959] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x7b54e65b776a400a [ 7180.282349] Lustre: *** cfs_fail_loc=302, val=2147483648*** [ 7181.068577] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7196.698825] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 7196.970989] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6615 to 0x240000400:6657) [ 7196.975731] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6549 to 0x280000400:6593) [ 7203.130877] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7204.659548] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7212.681658] Lustre: DEBUG MARKER: == replay-single test 73b: open(O_CREAT), unlink, replay, reconnect at open_replay reply, close ========================================================== 14:03:14 (1788804194) [ 7216.759790] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7219.339281] Lustre: Failing over lustre-MDT0000 [ 7221.260733] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.50@tcp (stopping) [ 7221.265995] Lustre: Skipped 4 previous similar messages [ 7221.585620] Lustre: server umount lustre-MDT0000 complete [ 7238.120115] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788804204/real 1788804204] req@ffff989186fc8700 x1875689706705920/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788804220 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 7238.122170] 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 [ 7238.144392] Lustre: 3313:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 32 previous similar messages [ 7238.144497] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7238.144500] LustreError: Skipped 3 previous similar messages [ 7238.234200] Lustre: Skipped 10 previous similar messages [ 7247.841023] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff989186fc8a80 x1875689706707712/t0(0) o250->MGC192.168.204.150@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 [ 7247.868120] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) Skipped 1 previous similar message [ 7248.291234] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7248.297547] Lustre: Skipped 5 previous similar messages [ 7253.156469] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7261.295539] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 7261.298609] LustreError: 159551:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9892a0db0700 x1875689692824320/t335007449091(335007449091) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:119/0 lens 592/608 e 0 to 0 dl 1788804254 ref 1 fl Interpret:/604/0 rc 301/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 7262.501923] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 7262.516030] Lustre: Skipped 10 previous similar messages [ 7277.700261] Lustre: lustre-MDT0000: Client 554b761e-e6ad-477b-bb92-ebd389a807c6 (at 192.168.204.50@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 7277.737233] Lustre: 159549:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9892a0db3100 x1875689692824320/t335007449091(335007449091) o101->554b761e-e6ad-477b-bb92-ebd389a807c6@192.168.204.50@tcp:136/0 lens 592/3488 e 0 to 0 dl 1788804271 ref 1 fl Interpret:/606/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 7277.912234] Lustre: lustre-MDT0000: Recovery over after 0:16, of 1 clients 1 recovered and 0 were evicted. [ 7277.926653] Lustre: Skipped 4 previous similar messages [ 7278.059549] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6615 to 0x240000400:6689) [ 7278.060072] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6595 to 0x280000400:6625) [ 7286.033303] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7287.647058] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7297.373148] Lustre: DEBUG MARKER: == replay-single test 74: Ensure applications don't fail waiting for OST recovery ========================================================== 14:04:38 (1788804278) [ 7302.544383] Lustre: Failing over lustre-OST0000 [ 7302.644464] Lustre: server umount lustre-OST0000 complete [ 7303.663661] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7303.708399] LustreError: 7918:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 8 previous similar messages [ 7308.176109] Lustre: Failing over lustre-MDT0000 [ 7308.526386] Lustre: server umount lustre-MDT0000 complete [ 7329.429980] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6595 to 0x280000400:6657) [ 7335.094235] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7342.601295] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 7342.611564] Lustre: Skipped 5 previous similar messages [ 7343.121349] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 7343.144302] Lustre: Skipped 5 previous similar messages [ 7343.154731] Lustre: lustre-OST0000: Denying connection for new client b291f159-2899-4388-b70d-eda81b83627b (at 192.168.204.50@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 7343.176069] Lustre: Skipped 11 previous similar messages [ 7347.776197] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6615 to 0x240000400:6721) [ 7348.717188] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7358.438995] Lustre: DEBUG MARKER: == replay-single test 80a: DNE: create remote dir, drop update rep from MDT0, fail MDT0 ========================================================== 14:05:40 (1788804340) [ 7359.744650] Lustre: DEBUG MARKER: SKIP: replay-single test_80a needs >= 2 MDTs [ 7361.543398] Lustre: DEBUG MARKER: == replay-single test 80b: DNE: create remote dir, drop update rep from MDT0, fail MDT1 ========================================================== 14:05:43 (1788804343) [ 7363.196764] Lustre: DEBUG MARKER: SKIP: replay-single test_80b needs >= 2 MDTs [ 7364.939769] Lustre: DEBUG MARKER: == replay-single test 80c: DNE: create remote dir, drop update rep from MDT1, fail MDT[0,1] ========================================================== 14:05:46 (1788804346) [ 7366.456918] Lustre: DEBUG MARKER: SKIP: replay-single test_80c needs >= 2 MDTs [ 7368.167469] Lustre: DEBUG MARKER: == replay-single test 80d: DNE: create remote dir, drop update rep from MDT1, fail 2 MDTs ========================================================== 14:05:49 (1788804349) [ 7369.746679] Lustre: DEBUG MARKER: SKIP: replay-single test_80d needs >= 2 MDTs [ 7371.532069] Lustre: DEBUG MARKER: == replay-single test 80e: DNE: create remote dir, drop MDT1 rep, fail MDT0 ========================================================== 14:05:53 (1788804353) [ 7373.102429] Lustre: DEBUG MARKER: SKIP: replay-single test_80e needs >= 2 MDTs [ 7375.120127] Lustre: DEBUG MARKER: == replay-single test 80f: DNE: create remote dir, drop MDT1 rep, fail MDT1 ========================================================== 14:05:56 (1788804356) [ 7376.582504] Lustre: DEBUG MARKER: SKIP: replay-single test_80f needs >= 2 MDTs [ 7378.030628] Lustre: DEBUG MARKER: == replay-single test 80g: DNE: create remote dir, drop MDT1 rep, fail MDT0, then MDT1 ========================================================== 14:05:59 (1788804359) [ 7379.281902] Lustre: DEBUG MARKER: SKIP: replay-single test_80g needs >= 2 MDTs [ 7380.757585] Lustre: DEBUG MARKER: == replay-single test 80h: DNE: create remote dir, drop MDT1 rep, fail 2 MDTs ========================================================== 14:06:02 (1788804362) [ 7381.977246] Lustre: DEBUG MARKER: SKIP: replay-single test_80h needs >= 2 MDTs [ 7383.645826] Lustre: DEBUG MARKER: == replay-single test 81a: DNE: unlink remote dir, drop MDT0 update rep, fail MDT1 ========================================================== 14:06:05 (1788804365) [ 7384.894258] Lustre: DEBUG MARKER: SKIP: replay-single test_81a needs >= 2 MDTs [ 7386.301197] Lustre: DEBUG MARKER: == replay-single test 81b: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0 ========================================================== 14:06:08 (1788804368) [ 7387.398678] Lustre: DEBUG MARKER: SKIP: replay-single test_81b needs >= 2 MDTs [ 7389.002122] Lustre: DEBUG MARKER: == replay-single test 81c: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0,MDT1 ========================================================== 14:06:10 (1788804370) [ 7390.298426] Lustre: DEBUG MARKER: SKIP: replay-single test_81c needs >= 2 MDTs [ 7392.240198] Lustre: DEBUG MARKER: == replay-single test 81d: DNE: unlink remote dir, drop MDT0 update reply, fail 2 MDTs ========================================================== 14:06:13 (1788804373) [ 7393.816641] Lustre: DEBUG MARKER: SKIP: replay-single test_81d needs >= 2 MDTs [ 7395.066838] Lustre: DEBUG MARKER: == replay-single test 81e: DNE: unlink remote dir, drop MDT1 req reply, fail MDT0 ========================================================== 14:06:17 (1788804377) [ 7396.309680] Lustre: DEBUG MARKER: SKIP: replay-single test_81e needs >= 2 MDTs [ 7397.921660] Lustre: DEBUG MARKER: == replay-single test 81f: DNE: unlink remote dir, drop MDT1 req reply, fail MDT1 ========================================================== 14:06:19 (1788804379) [ 7399.363293] Lustre: DEBUG MARKER: SKIP: replay-single test_81f needs >= 2 MDTs [ 7400.849537] Lustre: DEBUG MARKER: == replay-single test 81g: DNE: unlink remote dir, drop req reply, fail M0, then M1 ========================================================== 14:06:22 (1788804382) [ 7402.681478] Lustre: DEBUG MARKER: SKIP: replay-single test_81g needs >= 2 MDTs [ 7404.711270] Lustre: DEBUG MARKER: == replay-single test 81h: DNE: unlink remote dir, drop request reply, fail 2 MDTs ========================================================== 14:06:26 (1788804386) [ 7406.117261] Lustre: DEBUG MARKER: SKIP: replay-single test_81h needs >= 2 MDTs [ 7408.526169] Lustre: DEBUG MARKER: == replay-single test 84a: stale open during export disconnect ========================================================== 14:06:29 (1788804389) [ 7410.514588] Lustre: 164173:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting b291f159-2899-4388-b70d-eda81b83627b at adminstrative request [ 7420.982400] Lustre: DEBUG MARKER: == replay-single test 85a: check the cancellation of unused locks during recovery(IBITS) ========================================================== 14:06:42 (1788804402) [ 7429.892378] Lustre: Failing over lustre-MDT0000 [ 7430.141110] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.50@tcp (stopping) [ 7430.383213] Lustre: server umount lustre-MDT0000 complete [ 7450.633520] LustreError: 164937:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7450.648085] LustreError: 164937:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 5 previous similar messages [ 7454.186016] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6773 to 0x240000400:6817) [ 7454.196792] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6709 to 0x280000400:6753) [ 7456.611469] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7465.878902] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7467.438772] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7475.928903] Lustre: DEBUG MARKER: == replay-single test 85b: check the cancellation of unused locks during recovery(EXTENT) ========================================================== 14:07:37 (1788804457) [ 7490.957559] Lustre: Failing over lustre-OST0000 [ 7491.078484] Lustre: server umount lustre-OST0000 complete [ 7492.067795] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7515.916655] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7525.336563] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7526.729800] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7536.950834] Lustre: DEBUG MARKER: == replay-single test 86: umount server after clear nid_stats should not hit LBUG ========================================================== 14:08:38 (1788804518) [ 7542.869198] Lustre: Failing over lustre-MDT0000 [ 7543.402310] Lustre: server umount lustre-MDT0000 complete [ 7551.708994] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6709 to 0x280000400:6785) [ 7551.716928] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6918 to 0x240000400:6945) [ 7556.089929] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7567.027131] Lustre: DEBUG MARKER: == replay-single test 87a: write replay ================== 14:09:08 (1788804548) [ 7571.304868] LustreError: 168610:0:(osd_handler.c:720:osd_ro()) lustre-OST0000: *** setting device osd-zfs read-only *** [ 7571.316479] LustreError: 168610:0:(osd_handler.c:720:osd_ro()) Skipped 5 previous similar messages [ 7572.216887] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7575.201748] Lustre: Failing over lustre-OST0000 [ 7575.282466] Lustre: server umount lustre-OST0000 complete [ 7577.062731] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7579.660615] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7579.694717] LustreError: 14662:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 9 previous similar messages [ 7601.755629] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7611.769528] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7613.703363] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7624.506900] Lustre: DEBUG MARKER: == replay-single test 87b: write replay with changed data (checksum resend) ========================================================== 14:10:05 (1788804605) [ 7630.202994] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7634.965817] Lustre: Failing over lustre-OST0000 [ 7635.039677] Lustre: server umount lustre-OST0000 complete [ 7656.747849] LustreError: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.204.50@tcp inode [0x2000284a1:0x5:0x0] object 0x240000400:6946 extent [0-1048575]: client csum 571effa2, server csum 15dff77 [ 7662.818578] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7677.155874] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7679.129627] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7689.768715] Lustre: DEBUG MARKER: == replay-single test 88: MDS should not assign same objid to different files ========================================================== 14:11:10 (1788804670) [ 7694.183337] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7698.580240] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7705.448487] Lustre: Failing over lustre-MDT0000 [ 7705.736550] Lustre: server umount lustre-MDT0000 complete [ 7709.524672] LustreError: 128047:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788804692 with bad export cookie 8886981245228721819 [ 7719.917863] Lustre: Failing over lustre-OST0000 [ 7721.980034] Lustre: server umount lustre-OST0000 complete [ 7754.980398] LustreError: 3312:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff989183a47480 x1875689706848640/t0(0) o250->MGC192.168.204.150@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 [ 7760.300459] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7768.769796] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6826 to 0x280000400:6849) [ 7786.099243] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6947 to 0x240000400:6977) [ 7786.932683] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7807.653596] Lustre: DEBUG MARKER: == replay-single test 89: no disk space leak on late ost connection ========================================================== 14:13:08 (1788804788) [ 7826.430115] Lustre: Failing over lustre-OST0000 [ 7826.533395] Lustre: server umount lustre-OST0000 complete [ 7831.458842] Lustre: Failing over lustre-MDT0000 [ 7831.812530] Lustre: server umount lustre-MDT0000 complete [ 7838.715814] LustreError: 36640:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.50@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7838.737853] LustreError: 36640:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 34 previous similar messages [ 7848.225161] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788804814/real 1788804814] req@ffff989187ceb480 x1875689706874624/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788804830 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 7848.251866] Lustre: 3315:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 27 previous similar messages [ 7848.262659] 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 [ 7848.275685] Lustre: Skipped 11 previous similar messages [ 7848.280738] LustreError: MGC192.168.204.150@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7848.287625] LustreError: Skipped 4 previous similar messages [ 7859.057698] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7859.061215] Lustre: Skipped 9 previous similar messages [ 7859.494380] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6826 to 0x280000400:6881) [ 7863.599401] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7873.959574] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 7873.973675] Lustre: Skipped 12 previous similar messages [ 7875.458601] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7877.776764] Lustre: lustre-OST0000: Denying connection for new client 44f8718d-47e8-44c9-9e37-f2bc6d9de5fb (at 192.168.204.50@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:05 [ 7877.796577] Lustre: Skipped 1 previous similar message [ 7898.614695] Lustre: lustre-OST0000: Denying connection for new client 44f8718d-47e8-44c9-9e37-f2bc6d9de5fb (at 192.168.204.50@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:44 [ 7898.629899] Lustre: Skipped 3 previous similar messages [ 7934.450090] Lustre: lustre-OST0000: Denying connection for new client 44f8718d-47e8-44c9-9e37-f2bc6d9de5fb (at 192.168.204.50@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:09 [ 7934.480472] Lustre: Skipped 6 previous similar messages [ 7943.500266] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 7943.505196] Lustre: 176505:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client 649fc92a-4e18-49bc-b715-58ffd5d51481@ [ 7943.529439] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 7943.642161] Lustre: lustre-OST0000: Recovery over after 1:10, of 2 clients 1 recovered and 1 was evicted. [ 7943.654159] Lustre: Skipped 8 previous similar messages [ 7943.669841] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6988 to 0x240000400:7009) [ 7947.651903] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 61 sec [ 7962.611697] Lustre: DEBUG MARKER: free_before: 7520256 free_after: 7520256 [ 7968.836942] Lustre: DEBUG MARKER: == replay-single test 90: lfs find identifies the missing striped file segments ========================================================== 14:15:50 (1788804950) [ 7973.743179] Lustre: Failing over lustre-OST0001 [ 7973.830334] Lustre: server umount lustre-OST0001 complete [ 7992.620845] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [ 7992.625987] Lustre: Skipped 8 previous similar messages [ 7993.797988] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 7993.804503] Lustre: Skipped 8 previous similar messages [ 7998.091736] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8007.472774] Lustre: DEBUG MARKER: == replay-single test 93a: replay + reconnect ============ 14:16:29 (1788804989) [ 8011.216774] Lustre: Failing over lustre-OST0000 [ 8011.382177] Lustre: server umount lustre-OST0000 complete [ 8031.161790] LustreError: 179593:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 40000ms [ 8031.175919] LustreError: 179593:0:(ldlm_lib.c:2939:target_recovery_thread()) Skipped 36 previous similar messages [ 8036.316488] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8036.833082] Lustre: *** cfs_fail_loc=715, val=40*** [ 8046.563713] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 1:24 [ 8047.661211] Lustre: lustre-OST0000: Client 44f8718d-47e8-44c9-9e37-f2bc6d9de5fb (at 192.168.204.50@tcp) reconnected, waiting for 2 clients in recovery for 1:23 [ 8052.704913] Lustre: *** cfs_fail_loc=715, val=40*** [ 8052.708074] Lustre: Skipped 1 previous similar message [ 8053.728449] Lustre: *** cfs_fail_loc=715, val=40*** [ 8062.944878] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 1:08 [ 8069.088516] Lustre: *** cfs_fail_loc=715, val=40*** [ 8071.232133] LustreError: 179593:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 8071.246566] LustreError: 179593:0:(ldlm_lib.c:2939:target_recovery_thread()) Skipped 76 previous similar messages [ 8077.456406] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 8078.856789] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 8086.340637] Lustre: DEBUG MARKER: == replay-single test 93b: replay + reconnect on mds ===== 14:17:48 (1788805068) [ 8089.521201] Lustre: Failing over lustre-MDT0000 [ 8089.794426] Lustre: server umount lustre-MDT0000 complete [ 8108.542241] LustreError: 181190:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 80000ms [ 8111.072518] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8114.660039] Lustre: *** cfs_fail_loc=715, val=80*** [ 8114.668354] Lustre: Skipped 1 previous similar message [ 8124.918713] Lustre: lustre-MDT0000: Client 44f8718d-47e8-44c9-9e37-f2bc6d9de5fb (at 192.168.204.50@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 8124.944600] Lustre: Skipped 1 previous similar message [ 8131.041567] Lustre: *** cfs_fail_loc=715, val=80*** [ 8141.298070] Lustre: lustre-MDT0000: Client 44f8718d-47e8-44c9-9e37-f2bc6d9de5fb (at 192.168.204.50@tcp) reconnected, waiting for 1 clients in recovery for 0:37 [ 8147.424253] Lustre: *** cfs_fail_loc=715, val=80*** [ 8157.683821] Lustre: lustre-MDT0000: Client 44f8718d-47e8-44c9-9e37-f2bc6d9de5fb (at 192.168.204.50@tcp) reconnected, waiting for 1 clients in recovery for 0:20 [ 8188.608174] LustreError: 181190:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 8188.671253] Lustre: 181190:0:(ldlm_lib.c:2985:target_recovery_thread()) too long recovery - read logs [ 8188.686624] LustreError: dumping log to /tmp/lustre-log.1788805171.181190 [ 8188.858598] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:7023 to 0x240000400:7041) [ 8188.865471] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6894 to 0x280000400:6913) [ 8194.123522] Lustre: DEBUG MARKER: oleg450-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 8195.462585] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 8204.108400] Lustre: DEBUG MARKER: == replay-single test complete, duration 7907 sec ======== 14:19:45 (1788805185) [ 8205.724976] Lustre: DEBUG MARKER: === replay-single: start cleanup 14:19:47 (1788805187) === [ 8215.514328] Lustre: DEBUG MARKER: === replay-single: finish cleanup 14:19:57 (1788805197) === [ 8245.824466] Lustre: server umount lustre-MDT0000 complete [ 8249.128764] LustreError: 153355:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788805231 with bad export cookie 8886981245228734314 [ 8258.607247] Lustre: server umount lustre-OST0000 complete [ 8272.274133] Lustre: server umount lustre-OST0001 complete [ 8282.633964] Lustre: DEBUG MARKER: oleg450-server.virtnet: executing unload_modules_local [ 8284.882452] Key type lgssc unregistered [ 8285.122427] LNet: 183323:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8285.128387] LNetError: 183323:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 8285.142694] LNet: Removed LNI 192.168.204.150@tcp [ 8285.804501] Key type .llcrypt unregistered [ 8285.810806] Key type ._llcrypt unregistered