[ 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 485711372 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, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001013] APIC: Switch to symmetric I/O mode setup [ 0.003321] x2apic enabled [ 0.004009] Switched APIC routing to physical x2apic. [ 0.006009] kvm-guest: setup PV IPIs [ 0.009000] ..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.010015] pid_max: default: 32768 minimum: 301 [ 0.012126] LSM: Security Framework initializing [ 0.013062] Yama: becoming mindful. [ 0.014046] SELinux: Initializing. [ 0.015079] *** VALIDATE selinux *** [ 0.023412] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.028342] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029147] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030107] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031136] *** VALIDATE tmpfs *** [ 0.033459] *** VALIDATE proc *** [ 0.035212] *** VALIDATE cgroup *** [ 0.036009] *** VALIDATE cgroup2 *** [ 0.037259] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038171] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040030] Spectre V2 : User space: Vulnerable [ 0.042006] Speculative Store Bypass: Vulnerable [ 0.044983] debug: unmapping init [mem 0xffffffffae459000-0xffffffffae460fff] [ 0.047173] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.048714] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.049024] ... version: 2 [ 0.050019] ... bit width: 48 [ 0.051012] ... generic registers: 4 [ 0.052013] ... value mask: 0000ffffffffffff [ 0.053015] ... max period: 00007fffffffffff [ 0.054015] ... fixed-purpose events: 3 [ 0.055012] ... event mask: 000000070000000f [ 0.057243] rcu: Hierarchical SRCU implementation. [ 0.059549] smp: Bringing up secondary CPUs ... [ 0.060542] x86: Booting SMP configuration: [ 0.061027] .... node #0, CPUs: #1 #2 #3 [ 0.065037] smp: Brought up 1 node, 4 CPUs [ 0.067021] smpboot: Max logical packages: 1 [ 0.068019] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.235425] node 0 deferred pages initialised in 164ms [ 0.238012] devtmpfs: initialized [ 0.239326] x86/mm: Memory block size: 128MB [ 0.241922] gcov: version magic: 0x41383552 [ 0.243219] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.244094] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.245252] pinctrl core: initialized pinctrl subsystem [ 0.246210] [ 0.246910] ************************************************************* [ 0.247018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.248014] ** ** [ 0.249014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.250029] ** ** [ 0.251017] ** This means that this kernel is built to expose internal ** [ 0.252014] ** IOMMU data structures, which may compromise security on ** [ 0.253025] ** your system. ** [ 0.254013] ** ** [ 0.255016] ** If you see this message and you are not debugging the ** [ 0.256016] ** kernel, report this immediately to your vendor! ** [ 0.257077] ** ** [ 0.258015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.259014] ************************************************************* [ 0.260688] NET: Registered protocol family 16 [ 0.261514] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.262073] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.263069] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.264644] cpuidle: using governor menu [ 0.267198] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.270752] PCI: Using configuration type 1 for base access [ 0.272194] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.282095] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.285078] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.288183] cryptd: max_cpu_qlen set to 1000 [ 0.290260] ACPI: Added _OSI(Module Device) [ 0.291021] ACPI: Added _OSI(Processor Device) [ 0.292021] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.293018] ACPI: Added _OSI(Processor Aggregator Device) [ 0.297156] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.300580] ACPI: Interpreter enabled [ 0.301069] ACPI: PM: (supports S0 S3 S4 S5) [ 0.302014] ACPI: Using IOAPIC for interrupt routing [ 0.303107] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.304412] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.314586] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.315046] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.316028] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.317086] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.319331] acpiphp: Slot [2] registered [ 0.320208] acpiphp: Slot [5] registered [ 0.321192] acpiphp: Slot [6] registered [ 0.322212] acpiphp: Slot [7] registered [ 0.323168] acpiphp: Slot [8] registered [ 0.324156] acpiphp: Slot [9] registered [ 0.325182] acpiphp: Slot [10] registered [ 0.326164] acpiphp: Slot [3] registered [ 0.327114] acpiphp: Slot [4] registered [ 0.328130] acpiphp: Slot [11] registered [ 0.329135] acpiphp: Slot [12] registered [ 0.330105] acpiphp: Slot [13] registered [ 0.331109] acpiphp: Slot [14] registered [ 0.332221] acpiphp: Slot [15] registered [ 0.334196] acpiphp: Slot [16] registered [ 0.336226] acpiphp: Slot [17] registered [ 0.338272] acpiphp: Slot [18] registered [ 0.340169] acpiphp: Slot [19] registered [ 0.342139] acpiphp: Slot [20] registered [ 0.344160] acpiphp: Slot [21] registered [ 0.345113] acpiphp: Slot [22] registered [ 0.347107] acpiphp: Slot [23] registered [ 0.349120] acpiphp: Slot [24] registered [ 0.350110] acpiphp: Slot [25] registered [ 0.352118] acpiphp: Slot [26] registered [ 0.354198] acpiphp: Slot [27] registered [ 0.355104] acpiphp: Slot [28] registered [ 0.357122] acpiphp: Slot [29] registered [ 0.359119] acpiphp: Slot [30] registered [ 0.360100] acpiphp: Slot [31] registered [ 0.362116] PCI host bridge to bus 0000:00 [ 0.364024] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.366043] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.369036] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.372050] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.375039] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.377068] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.379373] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.383232] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.386542] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.399885] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.405020] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.408032] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.410038] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.412028] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.415419] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.418907] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.422053] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.427031] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.434015] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.449015] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.455015] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.460767] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.470026] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.479026] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.503027] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.514407] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.526015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.537019] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.560016] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.575597] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.590031] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.603048] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.643026] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.656495] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.673018] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.685023] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.705022] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.718379] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.730026] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.738026] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.760025] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.771141] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.779015] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.786015] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.804000] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.815478] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.818555] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.821457] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.824461] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.827306] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.832189] iommu: Default domain type: Passthrough [ 0.835507] SCSI subsystem initialized [ 0.837223] ACPI: bus type USB registered [ 0.838185] usbcore: registered new interface driver usbfs [ 0.840159] usbcore: registered new interface driver hub [ 0.842123] usbcore: registered new device driver usb [ 0.844224] pps_core: LinuxPPS API ver. 1 registered [ 0.846023] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.850097] PTP clock support registered [ 0.855049] EDAC MC: Ver: 3.0.0 [ 0.856594] PCI: Using ACPI for IRQ routing [ 0.859323] NetLabel: Initializing [ 0.861014] NetLabel: domain hash size = 128 [ 0.862010] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.864121] NetLabel: unlabeled traffic allowed by default [ 0.867146] vgaarb: loaded [ 0.868282] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.871019] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.879000] clocksource: Switched to clocksource kvm-clock [ 0.990887] VFS: Disk quotas dquot_6.6.0 [ 0.992511] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.995357] *** VALIDATE ramfs *** [ 0.997929] *** VALIDATE hugetlbfs *** [ 0.999373] pnp: PnP ACPI init [ 1.001539] pnp: PnP ACPI: found 6 devices [ 1.020422] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.023912] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.025923] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.028127] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.030413] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.032943] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.035637] NET: Registered protocol family 2 [ 1.037915] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.042401] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.045552] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.051433] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.055588] TCP: Hash tables configured (established 65536 bind 65536) [ 1.058225] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.061352] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.064507] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.068054] NET: Registered protocol family 1 [ 1.071230] RPC: Registered named UNIX socket transport module. [ 1.073413] RPC: Registered udp transport module. [ 1.075276] RPC: Registered tcp transport module. [ 1.076976] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.079301] NET: Registered protocol family 44 [ 1.081132] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.083755] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.086113] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.088637] PCI: CLS 0 bytes, default 64 [ 1.090436] Unpacking initramfs... [ 2.498777] debug: unmapping init [mem 0xffff9100bcc54000-0xffff9100bffbffff] [ 2.504440] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.506831] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.509651] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.002504] Initialise system trusted keyrings [ 3.005277] Key type blacklist registered [ 3.007610] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.017669] zbud: loaded [ 3.020967] *** VALIDATE nfs *** [ 3.022247] *** VALIDATE nfs4 *** [ 3.023837] pstore: using deflate compression [ 3.028112] Platform Keyring initialized [ 3.138125] NET: Registered protocol family 38 [ 3.140061] Key type asymmetric registered [ 3.141379] Asymmetric key parser 'x509' registered [ 3.143275] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.147076] io scheduler mq-deadline registered [ 3.149296] io scheduler kyber registered [ 3.150868] io scheduler bfq registered [ 3.152617] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.155956] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.161496] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.164897] ACPI: Power Button [PWRF] [ 3.170852] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.180369] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.205231] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.218357] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.254040] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.281564] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.312427] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.317845] Non-volatile memory driver v1.3 [ 3.319425] Linux agpgart interface v0.103 [ 3.351310] virtio_blk virtio1: [vda] 149952 512-byte logical blocks (76.8 MB/73.2 MiB) [ 3.354465] vda: detected capacity change from 0 to 76775424 [ 3.367984] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.371039] vdb: detected capacity change from 0 to 1073741824 [ 3.386314] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.389231] vdc: detected capacity change from 0 to 2621440000 [ 3.404730] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.408031] vdd: detected capacity change from 0 to 2621440000 [ 3.425891] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.429041] vde: detected capacity change from 0 to 4294967296 [ 3.446844] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.450319] vdf: detected capacity change from 0 to 4294967296 [ 3.458038] libphy: Fixed MDIO Bus: probed [ 3.476987] usbcore: registered new interface driver usbserial_generic [ 3.479681] usbserial: USB Serial support registered for generic [ 3.481890] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.485914] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.487644] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.490100] mousedev: PS/2 mouse device common for all mice [ 3.493661] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.499077] rtc_cmos 00:05: RTC can wake from S4 [ 3.500063] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.504071] rtc_cmos 00:05: registered as rtc0 [ 3.507300] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.508555] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.509940] intel_pstate: CPU model not supported [ 3.516563] hid: raw HID events driver (C) Jiri Kosina [ 3.518578] usbcore: registered new interface driver usbhid [ 3.520225] usbhid: USB HID core driver [ 3.521772] drop_monitor: Initializing network drop monitor service [ 3.523893] Initializing XFRM netlink socket [ 3.525667] NET: Registered protocol family 10 [ 3.528367] Segment Routing with IPv6 [ 3.529600] NET: Registered protocol family 17 [ 3.531368] mpls_gso: MPLS GSO support [ 3.537723] RAS: Correctable Errors collector initialized. [ 3.539965] AVX version of gcm_enc/dec engaged. [ 3.541814] AES CTR mode by8 optimization enabled [ 3.622520] sched_clock: Marking stable (3622486881, 0)->(4639061768, -1016574887) [ 3.626607] registered taskstats version 1 [ 3.630226] Loading compiled-in X.509 certificates [ 3.633961] zswap: loaded using pool lzo/zbud [ 3.661381] Key type big_key registered [ 3.676788] Key type encrypted registered [ 3.678657] ima: No TPM chip found, activating TPM-bypass! [ 3.680766] ima: Allocated hash algorithm: sha1 [ 3.682546] ima: No architecture policies found [ 3.684300] evm: Initialising EVM extended attributes: [ 3.686221] evm: security.selinux [ 3.687231] evm: security.ima [ 3.688101] evm: security.capability [ 3.688947] evm: HMAC attrs: 0x1 [ 3.691667] rtc_cmos 00:05: setting system clock to 2026-09-10 17:59:14 UTC (1789063154) [ 3.698196] debug: unmapping init [mem 0xffffffffaf403000-0xffffffffaf5fffff] [ 3.701447] debug: unmapping init [mem 0xffffffffae182000-0xffffffffae458fff] [ 3.710218] Write protecting the kernel read-only data: 28672k [ 3.713060] debug: unmapping init [mem 0xffffffffac803000-0xffffffffac9fffff] [ 3.715516] debug: unmapping init [mem 0xffffffffad114000-0xffffffffad1fffff] [ 3.758767] 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.767537] systemd[1]: Detected virtualization kvm. [ 3.769704] systemd[1]: Detected architecture x86-64. [ 3.771531] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.802287] systemd[1]: No hostname configured. [ 3.804227] systemd[1]: Set hostname to . [ 3.806638] random: systemd: uninitialized urandom read (16 bytes read) [ 3.810464] systemd[1]: Initializing machine ID from random generator. [ 3.904684] random: ln: uninitialized urandom read (6 bytes read) [ 4.005232] random: systemd: uninitialized urandom read (16 bytes read) [ 4.008219] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 4.013531] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 4.017480] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ OK ] Reached target Timers. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket. Starting Create list of required st…ce nodes for the current kernel... Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Paths. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.695887] device-mapper: uevent: version 1.0.3 [ 4.698308] 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. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 5.612384] random: fast init done [ 5.634928] virtio_net virtio0 ens2: renamed from eth0 [ 5.865416] scsi host0: ata_piix [ 5.906378] scsi host1: ata_piix [ 5.908271] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.910869] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.720441] dracut-initqueue[578]: RTNETLINK answers: File exists [ 10.195463] random: crng init done [ 10.197118] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 11.009490] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Timers. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Slices. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 12.353378] printk: systemd: 26 output lines suppressed due to ratelimiting [ 12.670188] SELinux: Disabled at runtime. [ 12.728717] 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.739405] systemd[1]: Detected virtualization kvm. [ 12.741579] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 13.477980] systemd[1]: initrd-switch-root.service: Succeeded. [ 13.482058] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 13.492910] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 13.497250] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 13.501841] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 13.518457] systemd[1]: Starting Journal Service... Starting Journal Service... [ 13.524644] systemd[1]: proc-sys-fs-binfmt_misc.automount: Refusing to start, unit to trigger not loaded. [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 ] Created slice User and Session Slice. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Control Socket. [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-getty.slice. Mounting Huge Pages File System... [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... Activating swap /dev/disk/by-label/SWAP... Starting Remount Root and Kernel File Systems... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Reached target Slices. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-serial\x2dgetty.slice. Mounting Kernel Debug File System... [ 13.673642] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Stopped target Initrd Root File System. Starting Apply Kernel Variables... Mounting POSIX Message Queue File System... [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted POSIX Message Queue File System. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started udev Coldplug all Devices. [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ 14.135583] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /mnt. [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 14.528194] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 14.592293] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 14.664750] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 14.684137] EDAC sbridge: Ver: 1.1.2 [ 16.425384] Key type dns_resolver registered [ 16.744635] NFS: Registering the id_resolver key type [ 16.746491] Key type id_resolver registered [ 16.749643] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started OpenSSH server daemon. Starting Hostname Service... [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg443-server login: [ 63.584487] spl: loading out-of-tree module taints kernel. [ 69.913349] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 83.616416] Key type ._llcrypt registered [ 83.622075] Key type .llcrypt registered [ 83.793151] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_hostid [ 105.761911] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing load_modules_local [ 107.211425] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 107.228638] alg: No test for adler32 (adler32-zlib) [ 109.020123] Lustre: Lustre: Build Version: 2.17.58_39_ga794951 [ 110.246688] LNet: Added LNI 192.168.204.143@tcp [8/256/0/180] [ 112.232246] Key type lgssc registered [ 113.975516] Lustre: Echo OBD driver; http://www.lustre.org/ [ 117.958653] hrtimer: interrupt took 3368890 ns [ 125.633704] vdc: vdc1 vdc9 [ 137.831077] vde: vde1 vde9 [ 148.963761] vdf: vdf1 vdf9 [ 171.650495] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing load_modules_local [ 183.473630] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 184.926306] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 185.229201] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 185.303448] Lustre: lustre-MDT0000: new disk, initializing [ 185.611834] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 185.665204] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 190.696879] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 195.994447] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 203.125065] Lustre: lustre-OST0000: new disk, initializing [ 203.133816] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 203.139112] Lustre: Skipped 1 previous similar message [ 203.240578] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 209.229728] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 209.246274] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 209.453687] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 211.776608] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 224.676385] Lustre: lustre-OST0001: new disk, initializing [ 224.683609] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 224.849354] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 231.853402] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 231.863130] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 232.058561] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 233.905959] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 248.196543] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 258.106935] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 266.443347] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing check_logdir /tmp/testlogs/ [ 273.153756] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing yml_node [ 278.878567] Lustre: DEBUG MARKER: Client: 2.17.58.39 [ 281.861516] Lustre: DEBUG MARKER: MDS: 2.17.58.39 [ 284.873135] Lustre: DEBUG MARKER: OSS: 2.17.58.39 [ 287.031739] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Thu Sep 10 14:03:56 EDT 2026 [ 309.059789] Lustre: DEBUG MARKER: excepting tests: 59 36 [ 311.390990] Lustre: DEBUG MARKER: === replay-single: start setup 14:04:20 (1789063460) === [ 318.245106] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing check_config_client /mnt/lustre [ 340.386869] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 345.408273] Lustre: 11329:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 351.502133] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 356.172931] Lustre: DEBUG MARKER: === replay-single: finish setup 14:05:04 (1789063504) === [ 358.710139] Lustre: DEBUG MARKER: == replay-single test 0a: empty replay =================== 14:05:07 (1789063507) [ 362.880830] LustreError: 11824:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 364.015657] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 366.531791] Lustre: Failing over lustre-MDT0000 [ 366.996625] Lustre: server umount lustre-MDT0000 complete [ 386.016209] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063520/real 1789063520] req@ffff91012f18fb80 x1875968798028800/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789063536 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 386.017079] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 386.084407] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 386.101773] 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 [ 391.200155] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063525/real 1789063525] req@ffff9101350eb480 x1875968798029184/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789063541 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 395.239649] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063530/real 1789063530] req@ffff9101355f9180 x1875968798029440/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789063546 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 395.311980] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 396.049753] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 396.162929] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 396.310370] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 400.354339] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063535/real 1789063535] req@ffff9101355fa680 x1875968798029952/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789063551 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 400.410842] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 401.301250] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 410.596503] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 413.220639] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 415.747030] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 427.843334] Lustre: DEBUG MARKER: == replay-single test 0b: ensure object created after recover exists. (3284) ========================================================== 14:06:16 (1789063576) [ 430.554305] Lustre: Failing over lustre-OST0000 [ 430.723645] Lustre: server umount lustre-OST0000 complete [ 431.080690] 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 [ 431.109306] Lustre: Skipped 1 previous similar message [ 436.194669] LustreError: 6707: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. [ 436.227096] LustreError: 6707:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [ 437.105428] LustreError: 6708:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 441.316069] LustreError: 6707: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. [ 446.437788] LustreError: 8227: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. [ 446.451808] LustreError: 8227:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 451.640647] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 452.465301] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 453.222586] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 453.223589] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 453.254159] Lustre: Skipped 1 previous similar message [ 460.185813] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 471.393506] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 473.063262] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 483.966468] Lustre: DEBUG MARKER: == replay-single test 0c: check replay-barrier =========== 14:07:13 (1789063633) [ 487.161384] LustreError: 14871:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 488.183826] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 491.009790] Lustre: Failing over lustre-MDT0000 [ 491.627971] Lustre: server umount lustre-MDT0000 complete [ 508.901663] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063643/real 1789063643] req@ffff91013530a300 x1875968798062848/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789063659 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 508.913092] 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 [ 508.954535] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 508.954672] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 508.999871] Lustre: Skipped 1 previous similar message [ 519.138176] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe3fc69a [ 519.146402] Lustre: MGC192.168.204.143@tcp: Connection restored to 0@lo (at 0@lo) [ 519.201207] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063653/real 1789063653] req@ffff91012c2f4000 x1875968798063616/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789063669 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 519.253933] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 519.847195] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 525.567509] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 528.818442] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 528.824775] Lustre: lustre-MDT0000: Denying connection for new client b3acc70d-6004-466e-9808-6b0628c260f1 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 533.888890] Lustre: lustre-MDT0000: Denying connection for new client b3acc70d-6004-466e-9808-6b0628c260f1 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:54 [ 533.992284] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 539.002486] Lustre: lustre-MDT0000: Denying connection for new client b3acc70d-6004-466e-9808-6b0628c260f1 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:49 [ 544.115073] Lustre: lustre-MDT0000: Denying connection for new client b3acc70d-6004-466e-9808-6b0628c260f1 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:44 [ 549.233131] Lustre: lustre-MDT0000: Denying connection for new client b3acc70d-6004-466e-9808-6b0628c260f1 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:39 [ 559.474867] Lustre: lustre-MDT0000: Denying connection for new client b3acc70d-6004-466e-9808-6b0628c260f1 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:29 [ 559.497171] Lustre: Skipped 1 previous similar message [ 579.956964] Lustre: lustre-MDT0000: Denying connection for new client b3acc70d-6004-466e-9808-6b0628c260f1 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:08 [ 579.981832] Lustre: Skipped 3 previous similar messages [ 588.500550] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 588.504715] Lustre: 15521:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 158a3706-68ad-4991-ab60-c512a871c0e9@ [ 588.518471] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 588.587266] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 588.616483] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:65) [ 588.628033] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:65) [ 600.791650] Lustre: DEBUG MARKER: == replay-single test 0d: expired recovery with no clients ========================================================== 14:09:09 (1789063749) [ 604.472747] LustreError: 16258:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 605.632477] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 608.004435] Lustre: Failing over lustre-MDT0000 [ 608.343134] Lustre: server umount lustre-MDT0000 complete [ 627.168274] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063761/real 1789063761] req@ffff91013655f800 x1875968798088192/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789063777 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 627.169323] 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 [ 627.174875] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 627.194769] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 627.246474] Lustre: Skipped 1 previous similar message [ 637.416536] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe3fca36 [ 637.426153] Lustre: MGC192.168.204.143@tcp: Connection restored to 0@lo (at 0@lo) [ 637.444338] Lustre: Skipped 1 previous similar message [ 638.252210] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 638.398389] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 644.618808] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 648.385286] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 648.393497] Lustre: lustre-MDT0000: Denying connection for new client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 648.436689] Lustre: Skipped 1 previous similar message [ 652.397071] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 708.500249] Lustre: lustre-MDT0000: recovery is timed out, evict stale exports [ 708.511934] Lustre: 16905:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client b3acc70d-6004-466e-9808-6b0628c260f1@ [ 708.535647] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 708.609661] Lustre: lustre-MDT0000: Recovery over after 1:00, of 1 clients 0 recovered and 1 was evicted. [ 708.667549] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:97) [ 708.687362] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:97) [ 721.428599] Lustre: DEBUG MARKER: == replay-single test 1: simple create =================== 14:11:10 (1789063870) [ 726.214435] LustreError: 17650:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 727.639332] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 730.491663] Lustre: Failing over lustre-MDT0000 [ 730.939229] Lustre: server umount lustre-MDT0000 complete [ 751.072760] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789063885/real 1789063885] req@ffff91013530a300 x1875968798112768/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789063901 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 751.084927] 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 [ 751.110861] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 751.110962] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 751.183954] Lustre: Skipped 1 previous similar message [ 760.307433] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe3fce7a [ 760.322215] Lustre: MGC192.168.204.143@tcp: Connection restored to 0@lo (at 0@lo) [ 760.341986] Lustre: Skipped 1 previous similar message [ 761.232607] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 761.321866] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 767.433652] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 771.957097] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 772.132195] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 772.198901] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:129) [ 772.202853] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:44 to 0x240000400:129) [ 780.540925] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 782.885886] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 792.942140] Lustre: DEBUG MARKER: == replay-single test 2a: touch ========================== 14:12:21 (1789063941) [ 796.676166] LustreError: 19247:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 798.104863] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 801.192523] Lustre: Failing over lustre-MDT0000 [ 801.254405] 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 [ 801.269031] Lustre: Skipped 1 previous similar message [ 801.271608] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 801.285183] Lustre: Skipped 1 previous similar message [ 801.804130] Lustre: server umount lustre-MDT0000 complete [ 822.473483] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 823.394784] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 828.274891] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 828.590382] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 828.647865] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:131 to 0x240000400:161) [ 828.650655] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:44 to 0x280000400:161) [ 830.011856] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 841.571061] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 841.585707] Lustre: Skipped 2 previous similar messages [ 841.657893] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 843.624926] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 853.257124] Lustre: DEBUG MARKER: == replay-single test 2b: touch ========================== 14:13:22 (1789064002) [ 857.498680] LustreError: 20836:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 858.946529] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 861.837623] Lustre: Failing over lustre-MDT0000 [ 862.190335] 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 [ 862.210614] Lustre: Skipped 1 previous similar message [ 862.211347] LustreError: 19853: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. [ 862.237981] LustreError: 19853:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 862.395041] Lustre: server umount lustre-MDT0000 complete [ 877.537752] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789064012/real 1789064012] req@ffff91012ba29c00 x1875968798147072/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789064028 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 877.582616] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 7 previous similar messages [ 877.591993] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 887.904978] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91013530b480 x1875968798148736/t0(0) o250->MGC192.168.204.143@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 [ 888.547260] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 888.557275] Lustre: Skipped 1 previous similar message [ 888.660149] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 889.721123] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 889.919395] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 889.990407] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:131 to 0x240000400:193) [ 889.996299] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:163 to 0x280000400:193) [ 894.307000] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 906.332712] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 908.029536] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 917.871705] Lustre: DEBUG MARKER: == replay-single test 2c: setstripe replay =============== 14:14:26 (1789064066) [ 921.945154] LustreError: 22441:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 923.364963] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 926.160668] Lustre: Failing over lustre-MDT0000 [ 926.809308] Lustre: server umount lustre-MDT0000 complete [ 945.122111] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 945.123559] 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 [ 954.343857] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe3fdc88 [ 954.365693] Lustre: MGC192.168.204.143@tcp: Connection restored to 0@lo (at 0@lo) [ 954.386453] Lustre: Skipped 3 previous similar messages [ 955.446081] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 956.276055] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 956.558562] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 956.658966] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:225) [ 956.662260] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:225) [ 961.847765] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 973.814872] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 976.330680] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 988.123242] Lustre: DEBUG MARKER: == replay-single test 2d: setdirstripe replay ============ 14:15:36 (1789064136) [ 992.323976] LustreError: 24030:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 993.564735] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 996.893747] Lustre: Failing over lustre-MDT0000 [ 997.284898] LustreError: 23050:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 997.299489] LustreError: 23050:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 997.360416] Lustre: server umount lustre-MDT0000 complete [ 1016.802092] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789064151/real 1789064151] req@ffff9101355f4a80 x1875968798182400/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789064167 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1016.803740] 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 [ 1016.842529] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1016.842595] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1016.899713] Lustre: Skipped 2 previous similar messages [ 1028.124861] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1028.138728] Lustre: Skipped 1 previous similar message [ 1028.403193] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1034.582695] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1038.263966] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1038.579968] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1038.686811] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:257) [ 1038.687025] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:257) [ 1047.509889] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1049.657963] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1059.617242] Lustre: DEBUG MARKER: == replay-single test 2e: O_CREAT|O_EXCL create replay === 14:16:48 (1789064208) [ 1061.218912] Lustre: *** cfs_fail_loc=13b, val=315*** [ 1061.225762] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 1061.236585] LustreError: 24637:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff910107af9880 x1875968776074240/t38654705666(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:374/0 lens 392/456 e 0 to 0 dl 1789064229 ref 1 fl Interpret:/600/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 1066.748353] LustreError: 25666:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1068.317812] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1072.321698] Lustre: Failing over lustre-MDT0000 [ 1073.124882] Lustre: server umount lustre-MDT0000 complete [ 1093.601123] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1103.844593] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91012ba28a80 x1875968798203392/t0(0) o250->MGC192.168.204.143@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 [ 1104.989981] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1108.195650] Lustre: 26281:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff91013d7d5500 x1875968776074240/t38654705666(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:420/0 lens 392/456 e 0 to 0 dl 1789064275 ref 1 fl Interpret:/602/0 rc 0/0 job:'openfile.0' uid:0 gid:0 projid:0 [ 1108.219605] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:289) [ 1108.222855] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:289) [ 1111.500062] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1118.884869] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1118.900639] Lustre: Skipped 4 previous similar messages [ 1124.460252] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1126.531072] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1138.006800] Lustre: DEBUG MARKER: == replay-single test 3a: replay failed open(O_DIRECTORY) ========================================================== 14:18:06 (1789064286) [ 1143.675275] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1146.043889] Lustre: Failing over lustre-MDT0000 [ 1146.428726] Lustre: server umount lustre-MDT0000 complete [ 1165.283231] 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 [ 1165.306979] Lustre: Skipped 2 previous similar messages [ 1176.408466] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1177.089148] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1177.100868] Lustre: Skipped 1 previous similar message [ 1177.296537] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1177.304208] Lustre: Skipped 1 previous similar message [ 1177.339869] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:321) [ 1177.349245] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:321) [ 1182.824954] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1195.431693] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1197.741796] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1207.533451] Lustre: DEBUG MARKER: == replay-single test 3b: replay failed open -ENOMEM ===== 14:19:16 (1789064356) [ 1211.968077] LustreError: 28851:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1211.978882] LustreError: 28851:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 1213.281474] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1214.364621] Lustre: *** cfs_fail_loc=114, val=0*** [ 1217.721991] Lustre: Failing over lustre-MDT0000 [ 1218.018038] Lustre: server umount lustre-MDT0000 complete [ 1236.385362] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1236.395878] LustreError: Skipped 1 previous similar message [ 1247.445482] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1247.850745] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:353) [ 1247.854537] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:353) [ 1253.788829] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1266.450791] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1268.949599] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1279.064805] Lustre: DEBUG MARKER: == replay-single test 3c: replay failed open -ENOMEM ===== 14:20:27 (1789064427) [ 1285.044477] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1286.193533] Lustre: *** cfs_fail_loc=128, val=0*** [ 1289.542235] Lustre: Failing over lustre-MDT0000 [ 1289.889803] Lustre: server umount lustre-MDT0000 complete [ 1308.449717] Lustre: 3304:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789064443/real 1789064443] req@ffff9101355f8a80 x1875968798257024/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789064459 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1308.477128] Lustre: 3304:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 33 previous similar messages [ 1318.881704] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91012f18b100 x1875968798258944/t0(0) o250->MGC192.168.204.143@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 [ 1319.306102] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.43@tcp (not set up) [ 1319.839072] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1319.851074] Lustre: Skipped 3 previous similar messages [ 1320.661747] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:195 to 0x240000400:385) [ 1320.662699] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:195 to 0x280000400:385) [ 1325.279722] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1337.854816] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1341.540986] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1353.469935] Lustre: DEBUG MARKER: == replay-single test 4a: |x| 10 open(O_CREAT)s ========== 14:21:42 (1789064502) [ 1358.293868] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1361.225349] Lustre: Failing over lustre-MDT0000 [ 1361.702716] Lustre: server umount lustre-MDT0000 complete [ 1391.636620] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1391.646779] Lustre: Skipped 1 previous similar message [ 1392.763985] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:391 to 0x240000400:417) [ 1392.769202] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:391 to 0x280000400:417) [ 1396.921887] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1405.926912] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1405.942310] Lustre: Skipped 7 previous similar messages [ 1408.701514] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1410.966089] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1421.381205] Lustre: DEBUG MARKER: == replay-single test 4b: |x| rm 10 files ================ 14:22:50 (1789064570) [ 1427.658650] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1430.697800] Lustre: Failing over lustre-MDT0000 [ 1431.111804] Lustre: server umount lustre-MDT0000 complete [ 1447.777149] 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 [ 1447.797691] Lustre: Skipped 7 previous similar messages [ 1464.504259] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1468.291878] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1468.319098] Lustre: Skipped 3 previous similar messages [ 1468.665678] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1468.674250] Lustre: Skipped 3 previous similar messages [ 1468.708166] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:423 to 0x240000400:449) [ 1468.708688] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:423 to 0x280000400:449) [ 1476.233413] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1478.047394] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1488.646551] Lustre: DEBUG MARKER: == replay-single test 5: |x| 220 open(O_CREAT) =========== 14:23:57 (1789064637) [ 1492.378741] LustreError: 35387:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 1492.384798] LustreError: 35387:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 1493.778162] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1505.166155] Lustre: Failing over lustre-MDT0000 [ 1505.656691] Lustre: server umount lustre-MDT0000 complete [ 1525.218417] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1525.230616] LustreError: Skipped 3 previous similar messages [ 1542.193453] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1554.818640] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:577) [ 1554.827156] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:577) [ 1562.815225] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1564.940503] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1592.637153] Lustre: DEBUG MARKER: == replay-single test 6a: mkdir + contained create ======= 14:25:41 (1789064741) [ 1597.816593] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1600.188731] Lustre: Failing over lustre-MDT0000 [ 1600.646879] Lustre: server umount lustre-MDT0000 complete [ 1628.132292] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe409db0 [ 1634.549737] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1642.613681] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:609) [ 1642.620307] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:609) [ 1652.011628] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1654.177419] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1666.926741] Lustre: DEBUG MARKER: == replay-single test 6b: |X| rmdir ====================== 14:26:55 (1789064815) [ 1674.124600] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1677.761680] Lustre: Failing over lustre-MDT0000 [ 1678.240302] Lustre: server umount lustre-MDT0000 complete [ 1706.340621] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1706.356643] Lustre: Skipped 3 previous similar messages [ 1712.491605] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1719.429476] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:641) [ 1719.430498] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:641) [ 1726.276668] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1728.422790] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1737.655390] Lustre: DEBUG MARKER: == replay-single test 7: mkdir |X| contained create ====== 14:28:06 (1789064886) [ 1742.650340] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1745.269692] Lustre: Failing over lustre-MDT0000 [ 1745.864114] Lustre: server umount lustre-MDT0000 complete [ 1766.282175] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.43@tcp (not set up) [ 1768.480738] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:673) [ 1768.482573] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:673) [ 1772.013761] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1783.239810] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1784.898137] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1795.506812] Lustre: DEBUG MARKER: == replay-single test 8: creat open |X| close ============ 14:29:04 (1789064944) [ 1799.675638] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1801.817771] Lustre: Failing over lustre-MDT0000 [ 1802.110269] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.43@tcp (stopping) [ 1802.295117] Lustre: server umount lustre-MDT0000 complete [ 1824.736211] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789064959/real 1789064959] req@ffff91013be7b480 x1875968798444416/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789064975 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1824.784697] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 71 previous similar messages [ 1829.860194] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe40ac0b [ 1835.552316] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1842.286321] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:705) [ 1842.286929] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:705) [ 1848.422136] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1850.555251] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1861.233741] Lustre: DEBUG MARKER: == replay-single test 9: |X| create (same inum/gen) ====== 14:30:09 (1789065009) [ 1866.792855] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1869.457116] Lustre: Failing over lustre-MDT0000 [ 1869.970320] Lustre: server umount lustre-MDT0000 complete [ 1898.284857] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1898.289153] Lustre: Skipped 7 previous similar messages [ 1900.681755] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:737) [ 1900.692660] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:737) [ 1903.880518] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1915.141337] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1917.325881] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1929.166632] Lustre: DEBUG MARKER: == replay-single test 10: create |X| rename unlink ======= 14:31:18 (1789065078) [ 1935.161959] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 1937.927819] Lustre: Failing over lustre-MDT0000 [ 1938.329426] Lustre: server umount lustre-MDT0000 complete [ 1965.030455] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe40b565 [ 1965.051083] Lustre: MGC192.168.204.143@tcp: Connection restored to 0@lo (at 0@lo) [ 1965.071964] Lustre: Skipped 17 previous similar messages [ 1967.748763] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:560 to 0x280000400:769) [ 1967.749297] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:560 to 0x240000400:769) [ 1971.907436] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1982.215383] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 1984.163208] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1993.981611] Lustre: DEBUG MARKER: == replay-single test 11: create open write rename |X| create-old-name read ========================================================== 14:32:22 (1789065142) [ 1999.037623] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2001.345070] Lustre: Failing over lustre-MDT0000 [ 2001.793422] Lustre: server umount lustre-MDT0000 complete [ 2019.808223] 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 [ 2019.822274] Lustre: Skipped 16 previous similar messages [ 2030.050659] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff910105d7b100 x1875968798498944/t0(0) o250->MGC192.168.204.143@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 [ 2036.452456] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2042.739739] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2042.753194] Lustre: Skipped 7 previous similar messages [ 2043.045474] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2043.054724] Lustre: Skipped 7 previous similar messages [ 2043.130416] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:801) [ 2043.133800] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:801) [ 2050.013377] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2051.928850] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2064.254620] Lustre: DEBUG MARKER: == replay-single test 12: open, unlink |X| close ========= 14:33:33 (1789065213) [ 2067.804222] LustreError: 48193:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2067.811750] LustreError: 48193:0:(osd_handler.c:720:osd_ro()) Skipped 7 previous similar messages [ 2068.697978] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2071.801347] Lustre: Failing over lustre-MDT0000 [ 2072.299177] Lustre: server umount lustre-MDT0000 complete [ 2090.272571] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2090.287597] LustreError: Skipped 7 previous similar messages [ 2100.712802] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe40bff3 [ 2108.676438] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2114.734293] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:833) [ 2114.737203] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:771 to 0x280000400:833) [ 2120.093447] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2122.014195] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2130.140960] Lustre: DEBUG MARKER: == replay-single test 13: open chmod 0 |x| write close === 14:34:39 (1789065279) [ 2135.126158] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2137.115532] Lustre: Failing over lustre-MDT0000 [ 2137.504988] Lustre: server umount lustre-MDT0000 complete [ 2162.625681] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2165.874220] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:835 to 0x280000400:865) [ 2165.875666] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:771 to 0x240000400:865) [ 2174.177325] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2176.365127] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2187.229798] Lustre: DEBUG MARKER: == replay-single test 14: open(O_CREAT), unlink |X| close ========================================================== 14:35:36 (1789065336) [ 2191.429550] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2194.107476] Lustre: Failing over lustre-MDT0000 [ 2194.409039] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2194.422903] Lustre: Skipped 1 previous similar message [ 2194.572278] Lustre: server umount lustre-MDT0000 complete [ 2227.076835] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2227.090299] Lustre: Skipped 7 previous similar messages [ 2234.215217] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2237.712461] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:867 to 0x240000400:897) [ 2237.712461] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:835 to 0x280000400:897) [ 2245.995919] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2248.521369] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2258.295685] Lustre: DEBUG MARKER: == replay-single test 15: open(O_CREAT), unlink |X| touch new, close ========================================================== 14:36:47 (1789065407) [ 2262.757591] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2265.104856] Lustre: Failing over lustre-MDT0000 [ 2265.567347] Lustre: server umount lustre-MDT0000 complete [ 2291.211298] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2293.919597] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:899 to 0x280000400:929) [ 2293.919949] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:899 to 0x240000400:929) [ 2302.386619] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2304.626223] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2315.142840] Lustre: DEBUG MARKER: == replay-single test 16: |X| open(O_CREAT), unlink, touch new, unlink new ========================================================== 14:37:44 (1789065464) [ 2320.221637] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2322.548778] Lustre: Failing over lustre-MDT0000 [ 2323.066847] Lustre: server umount lustre-MDT0000 complete [ 2343.632890] LustreError: 55132: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. [ 2343.684319] LustreError: 55132:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 2351.287278] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:931 to 0x280000400:961) [ 2351.291349] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:899 to 0x240000400:961) [ 2351.347474] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2364.972807] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2367.114906] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2379.221637] Lustre: DEBUG MARKER: == replay-single test 17: |X| open(O_CREAT), |replay| close ========================================================== 14:38:47 (1789065527) [ 2385.216809] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2387.702528] Lustre: Failing over lustre-MDT0000 [ 2388.077900] Lustre: server umount lustre-MDT0000 complete [ 2417.529138] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.43@tcp (not set up) [ 2419.419235] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:899 to 0x240000400:993) [ 2419.423758] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:963 to 0x280000400:993) [ 2424.484676] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2438.075135] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2439.750638] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2450.313201] Lustre: DEBUG MARKER: == replay-single test 18: open(O_CREAT), unlink, touch new, close, touch, unlink ========================================================== 14:39:59 (1789065599) [ 2455.673724] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2459.172059] Lustre: Failing over lustre-MDT0000 [ 2459.588329] Lustre: server umount lustre-MDT0000 complete [ 2477.290930] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789065612/real 1789065612] req@ffff91013d08bb80 x1875968798621824/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789065628 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2477.317798] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 75 previous similar messages [ 2490.528822] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:995 to 0x280000400:1025) [ 2490.532347] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:995 to 0x240000400:1025) [ 2493.438174] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2505.309463] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2507.605705] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2518.976268] Lustre: DEBUG MARKER: == replay-single test 19: mcreate, open, write, rename === 14:41:07 (1789065667) [ 2524.747295] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2527.476223] Lustre: Failing over lustre-MDT0000 [ 2527.844508] Lustre: server umount lustre-MDT0000 complete [ 2555.456153] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2555.463201] Lustre: Skipped 9 previous similar messages [ 2557.101417] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1027 to 0x280000400:1057) [ 2557.105307] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1027 to 0x240000400:1057) [ 2561.711770] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2573.129170] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2575.042187] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2584.896886] Lustre: DEBUG MARKER: == replay-single test 20a: |X| open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 14:42:14 (1789065734) [ 2589.731956] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2592.414813] Lustre: Failing over lustre-MDT0000 [ 2592.647680] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.43@tcp (stopping) [ 2592.788773] Lustre: server umount lustre-MDT0000 complete [ 2623.970860] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91013be78a80 x1875968798660352/t0(0) o250->MGC192.168.204.143@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 [ 2630.769263] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2632.854587] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1027 to 0x240000400:1089) [ 2632.863176] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1059 to 0x280000400:1089) [ 2638.822616] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2638.839482] Lustre: Skipped 21 previous similar messages [ 2643.720267] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2645.810812] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2657.862878] Lustre: DEBUG MARKER: == replay-single test 20b: write, unlink, eviction, replay (test mds_cleanup_orphans) ========================================================== 14:43:26 (1789065806) [ 2664.645930] Lustre: 62523:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 0a642e2b-1ad1-4091-83a2-560e605db3b3 at adminstrative request [ 2667.047879] LustreError: 6711:0:(ofd_io.c:785:ofd_preprw_write()) lustre-OST0000: BRW to missing obj 0x240000400:1090 [ 2672.308959] Lustre: Failing over lustre-MDT0000 [ 2672.840987] Lustre: server umount lustre-MDT0000 complete [ 2691.040441] 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 [ 2691.044434] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2691.059051] Lustre: Skipped 18 previous similar messages [ 2691.079363] LustreError: Skipped 8 previous similar messages [ 2700.264625] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe40ed2d [ 2707.159769] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2714.483385] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2714.502701] Lustre: Skipped 9 previous similar messages [ 2714.588157] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2714.602226] Lustre: Skipped 9 previous similar messages [ 2714.671697] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1091 to 0x240000400:1121) [ 2714.674847] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1059 to 0x280000400:1121) [ 2721.956292] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2724.243759] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2731.737538] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 2749.794875] Lustre: DEBUG MARKER: before 4096, after 4096 [ 2757.044860] Lustre: DEBUG MARKER: == replay-single test 20c: check that client eviction does not affect file content ========================================================== 14:45:06 (1789065906) [ 2758.104434] Lustre: 64621:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 0a642e2b-1ad1-4091-83a2-560e605db3b3 at adminstrative request [ 2769.846114] Lustre: DEBUG MARKER: == replay-single test 21: |X| open(O_CREAT), unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 14:45:18 (1789065918) [ 2773.421501] LustreError: 64967:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 2773.428185] LustreError: 64967:0:(osd_handler.c:720:osd_ro()) Skipped 8 previous similar messages [ 2774.581760] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2776.693059] Lustre: Failing over lustre-MDT0000 [ 2777.012333] Lustre: server umount lustre-MDT0000 complete [ 2804.194424] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9101355faa00 x1875968798703744/t0(0) o250->MGC192.168.204.143@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 [ 2806.970333] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1123 to 0x280000400:1153) [ 2806.974856] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1124 to 0x240000400:1153) [ 2810.303708] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2822.893431] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2824.792519] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2835.637961] Lustre: DEBUG MARKER: == replay-single test 22: open(O_CREAT), |X| unlink, replay, close (test mds_cleanup_orphans) ========================================================== 14:46:24 (1789065984) [ 2840.699189] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2843.221145] Lustre: Failing over lustre-MDT0000 [ 2843.535532] Lustre: server umount lustre-MDT0000 complete [ 2871.266753] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe40f72f [ 2871.930245] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2871.964667] Lustre: Skipped 8 previous similar messages [ 2874.396715] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1155 to 0x240000400:1185) [ 2874.403285] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1155 to 0x280000400:1185) [ 2877.264192] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2889.117461] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2891.086231] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2901.577846] Lustre: DEBUG MARKER: == replay-single test 23: open(O_CREAT), |X| unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 14:47:30 (1789066050) [ 2906.857823] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2909.446218] Lustre: Failing over lustre-MDT0000 [ 2909.802753] Lustre: server umount lustre-MDT0000 complete [ 2944.545461] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2951.305225] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1187 to 0x280000400:1217) [ 2951.306101] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1187 to 0x240000400:1217) [ 2957.900909] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 2960.142247] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2970.293951] Lustre: DEBUG MARKER: == replay-single test 24: open(O_CREAT), replay, unlink, close (test mds_cleanup_orphans) ========================================================== 14:48:39 (1789066119) [ 2976.348425] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 2978.487425] Lustre: Failing over lustre-MDT0000 [ 2978.824946] Lustre: server umount lustre-MDT0000 complete [ 3006.117892] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3007.669050] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1219 to 0x280000400:1249) [ 3007.673212] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1219 to 0x240000400:1249) [ 3018.455396] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3021.095832] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3034.705965] Lustre: DEBUG MARKER: == replay-single test 25: open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 14:49:43 (1789066183) [ 3039.785962] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3042.604661] Lustre: Failing over lustre-MDT0000 [ 3043.030628] Lustre: server umount lustre-MDT0000 complete [ 3077.725435] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3078.176199] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789066212/real 1789066212] req@ffff91011079aa00 x1875968798772864/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789066228 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3078.201182] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 79 previous similar messages [ 3084.356911] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1251 to 0x240000400:1281) [ 3084.357607] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1219 to 0x280000400:1281) [ 3091.361629] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3093.459397] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3103.935557] Lustre: DEBUG MARKER: == replay-single test 26: |X| open(O_CREAT), unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 14:50:52 (1789066252) [ 3109.463138] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3112.273882] Lustre: Failing over lustre-MDT0000 [ 3112.438204] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3112.451284] Lustre: Skipped 1 previous similar message [ 3112.656538] Lustre: server umount lustre-MDT0000 complete [ 3131.263684] LustreError: 73514:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3133.462394] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1283 to 0x280000400:1313) [ 3133.462467] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1283 to 0x240000400:1313) [ 3136.516396] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3146.859263] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3148.781760] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3158.629268] Lustre: DEBUG MARKER: == replay-single test 27: |X| open(O_CREAT), unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 14:51:47 (1789066307) [ 3162.499491] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3165.395591] Lustre: Failing over lustre-MDT0000 [ 3165.951357] Lustre: server umount lustre-MDT0000 complete [ 3194.340355] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91013d08bb80 x1875968798808064/t0(0) o250->MGC192.168.204.143@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 [ 3194.902373] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3194.906132] Lustre: Skipped 8 previous similar messages [ 3199.915314] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3208.297022] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1315 to 0x240000400:1345) [ 3208.297356] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1315 to 0x280000400:1345) [ 3214.362199] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3215.994520] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3226.916986] Lustre: DEBUG MARKER: == replay-single test 28: open(O_CREAT), |X| unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 14:52:55 (1789066375) [ 3231.823449] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3234.622320] Lustre: Failing over lustre-MDT0000 [ 3235.227526] Lustre: server umount lustre-MDT0000 complete [ 3262.433024] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91013627b100 x1875968798825856/t0(0) o250->MGC192.168.204.143@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 [ 3264.765754] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1347 to 0x280000400:1377) [ 3264.768517] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1347 to 0x240000400:1377) [ 3268.484541] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3277.287735] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3277.291122] Lustre: Skipped 19 previous similar messages [ 3282.112203] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3284.678381] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3295.316421] Lustre: DEBUG MARKER: == replay-single test 29: open(O_CREAT), |X| unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 14:54:04 (1789066444) [ 3301.211602] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3304.053398] Lustre: Failing over lustre-MDT0000 [ 3304.703858] Lustre: server umount lustre-MDT0000 complete [ 3323.360199] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3323.361195] 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 [ 3323.373048] LustreError: Skipped 8 previous similar messages [ 3323.408331] Lustre: Skipped 18 previous similar messages [ 3339.394975] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3346.294974] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3346.308489] Lustre: Skipped 8 previous similar messages [ 3346.556097] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3346.562234] Lustre: Skipped 8 previous similar messages [ 3346.599854] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1379 to 0x280000400:1409) [ 3346.608678] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1379 to 0x240000400:1409) [ 3353.014712] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3354.435404] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3364.681100] Lustre: DEBUG MARKER: == replay-single test 30: open(O_CREAT) two, unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 14:55:13 (1789066513) [ 3370.072501] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3372.788068] Lustre: Failing over lustre-MDT0000 [ 3373.153735] Lustre: server umount lustre-MDT0000 complete [ 3399.654107] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe412095 [ 3402.846288] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1411 to 0x240000400:1441) [ 3402.846369] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1411 to 0x280000400:1441) [ 3406.074502] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3416.201920] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3417.712198] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3425.672782] Lustre: DEBUG MARKER: == replay-single test 31: open(O_CREAT) two, unlink one, |X| unlink one, close two (test mds_cleanup_orphans) ========================================================== 14:56:14 (1789066574) [ 3428.964541] LustreError: 80894:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 3428.970129] LustreError: 80894:0:(osd_handler.c:720:osd_ro()) Skipped 9 previous similar messages [ 3429.949323] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3432.034171] Lustre: Failing over lustre-MDT0000 [ 3432.590708] Lustre: server umount lustre-MDT0000 complete [ 3456.953307] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3460.152500] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1443 to 0x280000400:1473) [ 3460.152900] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1443 to 0x240000400:1473) [ 3468.114874] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3470.226800] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3480.075465] Lustre: DEBUG MARKER: == replay-single test 32: close() notices client eviction; close() after client eviction ========================================================== 14:57:09 (1789066629) [ 3481.191534] Lustre: 82386:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 0a642e2b-1ad1-4091-83a2-560e605db3b3 at adminstrative request [ 3492.490650] Lustre: DEBUG MARKER: == replay-single test 33a: fid seq shouldn't be reused after abort recovery ========================================================== 14:57:21 (1789066641) [ 3496.004749] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3497.746524] Lustre: Failing over lustre-MDT0000 [ 3497.991985] Lustre: server umount lustre-MDT0000 complete [ 3507.027983] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3507.030599] Lustre: lustre-MDT0000: Aborting client recovery [ 3507.032132] Lustre: Skipped 9 previous similar messages [ 3507.038298] LustreError: 83293:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3507.043670] Lustre: 83341:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3507.048931] Lustre: 83341:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 0a642e2b-1ad1-4091-83a2-560e605db3b3@ [ 3507.055697] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3507.099822] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 3507.189279] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1479 to 0x280000400:1505) [ 3507.192257] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1480 to 0x240000400:1505) [ 3511.457589] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3525.199117] Lustre: DEBUG MARKER: == replay-single test 33b: test fid seq allocation ======= 14:57:54 (1789066674) [ 3530.073831] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3531.979449] Lustre: Failing over lustre-MDT0000 [ 3532.182202] Lustre: server umount lustre-MDT0000 complete [ 3541.051983] Lustre: *** cfs_fail_loc=1311, val=0*** [ 3541.071927] Lustre: lustre-MDT0000: Aborting client recovery [ 3541.075390] LustreError: 84655:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3541.080391] Lustre: 84703:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3541.085421] Lustre: 84703:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3541.092567] Lustre: 84703:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 0a642e2b-1ad1-4091-83a2-560e605db3b3@ [ 3541.100156] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3541.153038] Lustre: lustre-MDT0000-osd: cancel update llog [0x200015bc0:0x1:0x0] [ 3541.223956] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1516 to 0x280000400:1537) [ 3541.224204] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1516 to 0x240000400:1537) [ 3545.558344] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3551.376764] Lustre: *** cfs_fail_loc=1311, val=0*** [ 3558.081577] Lustre: DEBUG MARKER: == replay-single test 34: abort recovery before client does replay (test mds_cleanup_orphans) ========================================================== 14:58:27 (1789066707) [ 3562.285838] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3564.435726] Lustre: Failing over lustre-MDT0000 [ 3564.786619] Lustre: server umount lustre-MDT0000 complete [ 3574.057699] Lustre: lustre-MDT0000: Aborting client recovery [ 3574.060450] LustreError: 86023:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3574.064742] Lustre: 86070:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3574.069959] Lustre: 86070:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3574.074359] Lustre: 86070:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 0a642e2b-1ad1-4091-83a2-560e605db3b3@ [ 3574.080578] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3574.117198] Lustre: lustre-MDT0000-osd: cancel update llog [0x200016778:0x1:0x0] [ 3574.196021] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1543 to 0x240000400:1569) [ 3574.198909] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1544 to 0x280000400:1569) [ 3579.113854] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3592.790438] Lustre: DEBUG MARKER: == replay-single test 35: test recovery from llog for unlink op ========================================================== 14:59:01 (1789066741) [ 3594.081231] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 3594.090045] LustreError: 86033:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff910107548a80 x1875968777110272/t201863462916(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:635/0 lens 512/456 e 0 to 0 dl 1789066755 ref 1 fl Interpret:/200/0 rc 0/0 job:'rm.0' uid:0 gid:0 projid:4294967295 [ 3598.526510] Lustre: Failing over lustre-MDT0000 [ 3598.913507] Lustre: server umount lustre-MDT0000 complete [ 3610.106228] Lustre: lustre-MDT0000: Not available for connect from 0@lo (not set up) [ 3610.448255] Lustre: lustre-MDT0000: Aborting client recovery [ 3610.450663] LustreError: 87250:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3610.459252] Lustre: 87298:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3610.469481] Lustre: 87298:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3610.477464] Lustre: 87298:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 0a642e2b-1ad1-4091-83a2-560e605db3b3@ [ 3610.488031] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3610.532611] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017330:0x1:0x0] [ 3610.650687] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1543 to 0x240000400:1601) [ 3610.657180] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1571 to 0x280000400:1601) [ 3615.985122] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3628.938413] Lustre: DEBUG MARKER: SKIP: replay-single test_36 skipping ALWAYS excluded test 36 [ 3630.724609] Lustre: DEBUG MARKER: == replay-single test 37: abort recovery before client does replay (test mds_cleanup_orphans for directories) ========================================================== 14:59:39 (1789066779) [ 3634.861350] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3637.926616] Lustre: Failing over lustre-MDT0000 [ 3638.285161] Lustre: server umount lustre-MDT0000 complete [ 3648.230609] Lustre: lustre-MDT0000: Aborting client recovery [ 3648.232783] LustreError: 88721:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 3648.239269] Lustre: 88767:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 3648.244709] Lustre: 88767:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 3648.249759] Lustre: 88767:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 0a642e2b-1ad1-4091-83a2-560e605db3b3@ [ 3648.256544] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 3648.318684] Lustre: lustre-MDT0000-osd: cancel update llog [0x200017b00:0x1:0x0] [ 3648.437359] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:1571 to 0x280000400:1633) [ 3648.445055] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:1543 to 0x240000400:1633) [ 3654.402812] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3668.973692] Lustre: DEBUG MARKER: == replay-single test 38: test recovery from unlink llog (test llog_gen_rec) ========================================================== 15:00:18 (1789066818) [ 3706.076910] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3708.168974] Lustre: Failing over lustre-MDT0000 [ 3708.460293] Lustre: server umount lustre-MDT0000 complete [ 3725.792825] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789066860/real 1789066860] req@ffff9101355fb100 x1875968799040000/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789066876 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3725.817818] Lustre: 3305:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 65 previous similar messages [ 3736.032965] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff910105d7d880 x1875968799041920/t0(0) o250->MGC192.168.204.143@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 [ 3737.583087] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2034 to 0x280000400:2049) [ 3737.584841] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2034 to 0x240000400:2049) [ 3742.496565] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3754.089827] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3756.057924] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3782.471706] Lustre: DEBUG MARKER: == replay-single test 39: test recovery from unlink llog (test llog_gen_rec) ========================================================== 15:02:11 (1789066931) [ 3808.595588] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 3820.200093] Lustre: Failing over lustre-MDT0000 [ 3820.680357] Lustre: server umount lustre-MDT0000 complete [ 3838.654388] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3838.659198] Lustre: Skipped 10 previous similar messages [ 3842.804706] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3844.374761] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2450 to 0x280000400:2465) [ 3844.375605] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2450 to 0x240000400:2465) [ 3852.443372] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 3853.786850] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3877.617732] Lustre: DEBUG MARKER: == replay-single test 41: read from a valid osc while other oscs are invalid ========================================================== 15:03:46 (1789067026) [ 3879.911683] Lustre: setting import lustre-OST0001_UUID INACTIVE by administrator request [ 3880.861577] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 3880.873396] LustreError: lustre-OST0001-osc-MDT0000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 3880.902367] Lustre: lustre-OST0001-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 3880.920081] Lustre: Skipped 22 previous similar messages [ 3888.011899] Lustre: DEBUG MARKER: == replay-single test 42: recovery after ost failure ===== 15:03:56 (1789067036) [ 3913.246263] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 3925.453803] Lustre: Failing over lustre-OST0000 [ 3925.568758] Lustre: server umount lustre-OST0000 complete [ 3925.994248] 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 [ 3926.006714] Lustre: Skipped 19 previous similar messages [ 3926.012253] LustreError: 36703: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. [ 3926.943432] LustreError: 36708:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3931.105394] LustreError: 36702: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. [ 3936.228524] LustreError: 36710: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. [ 3936.251501] LustreError: 36710:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 3941.347945] LustreError: 36700: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. [ 3941.369339] LustreError: 36700:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 3946.709544] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3946.715505] Lustre: Skipped 4 previous similar messages [ 3947.779476] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3947.788628] Lustre: Skipped 4 previous similar messages [ 3952.130292] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4015.802815] Lustre: DEBUG MARKER: == replay-single test 43: mds osc import failure during recovery; don't LBUG ========================================================== 15:06:04 (1789067164) [ 4020.654312] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4023.651196] Lustre: Failing over lustre-MDT0000 [ 4023.971604] Lustre: server umount lustre-MDT0000 complete [ 4043.083237] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4043.099306] LustreError: Skipped 9 previous similar messages [ 4043.263030] LustreError: 96718: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. [ 4043.279561] LustreError: 96718:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 4048.945235] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4049.929473] Lustre: *** cfs_fail_loc=204, val=2147483648*** [ 4049.941222] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2913) [ 4059.916982] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4061.799977] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4065.248312] LustreError: 96746:0:(osp_precreate.c:974:osp_precreate_cleanup_orphans()) lustre-OST0001-osc-MDT0000: cannot cleanup orphans: rc = -11 [ 4065.249880] Lustre: lustre-OST0001: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 4066.273238] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2881) [ 4082.496946] Lustre: DEBUG MARKER: == replay-single test 44a: race in target handle connect ========================================================== 15:07:11 (1789067231) [ 4088.072711] LustreError: 96720:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 4093.409813] LustreError: 96720:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 4093.428472] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4093.495445] LustreError: 36701:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 waking [ 4095.854150] LustreError: 96719:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 4101.090317] LustreError: 96719:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 4101.101662] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4103.096095] LustreError: 97126:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 4108.256203] LustreError: 97126:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 4108.269382] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4110.650366] LustreError: 96720:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 4115.938932] LustreError: 96720:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 4118.232940] LustreError: 96720:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 4123.620652] LustreError: 96720:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 4123.630388] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4123.642737] Lustre: Skipped 1 previous similar message [ 4133.663554] LustreError: 97126:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 4133.677617] LustreError: 97126:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 1 previous similar message [ 4138.979497] LustreError: 97126:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 4139.000840] LustreError: 97126:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 1 previous similar message [ 4147.681384] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4147.708677] Lustre: Skipped 2 previous similar messages [ 4150.208652] LustreError: 96719:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_race id 701 sleeping [ 4150.225949] LustreError: 96719:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 1 previous similar message [ 4155.360097] LustreError: 96719:0:(ldlm_lib.c:1185:target_handle_connect()) cfs_fail_race id 701 awake: rc=0 [ 4155.372171] LustreError: 96719:0:(ldlm_lib.c:1185:target_handle_connect()) Skipped 1 previous similar message [ 4174.687911] Lustre: DEBUG MARKER: == replay-single test 44b: race in target handle connect ========================================================== 15:08:43 (1789067323) [ 4177.537372] LustreError: 96720:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4188.019442] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4192.050764] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4197.233364] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4200.371892] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4207.474737] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4207.486565] Lustre: Skipped 1 previous similar message [ 4217.592214] LustreError: 96720:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4217.599562] Lustre: 96720:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff910105d7f480 x1875968779753472/t0(0) o38->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:0/0 lens 520/416 e 0 to 0 dl 1789067348 ref 1 fl Complete:H/200/0 rc 0/0 job:'lctl.0' uid:0 gid:0 projid:4294967295 [ 4217.712988] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4217.727858] Lustre: Skipped 3 previous similar messages [ 4217.732477] LustreError: 96719:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4242.291571] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4242.304983] Lustre: Skipped 1 previous similar message [ 4257.792137] LustreError: 96719:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4257.808547] Lustre: 96719:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff91013be7ad80 x1875968779756288/t0(0) o38->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:0/0 lens 520/416 e 0 to 0 dl 1789067388 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4262.781189] LustreError: 96718:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4287.347790] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4287.362223] Lustre: Skipped 4 previous similar messages [ 4302.848848] LustreError: 96718:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4302.860690] Lustre: 96718:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff910005b69c00 x1875968779758464/t0(0) o38->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:0/0 lens 520/416 e 0 to 0 dl 1789067433 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4307.316700] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4307.325408] Lustre: Skipped 1 previous similar message [ 4307.329050] LustreError: 96720:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4332.917269] Lustre: lustre-MDT0000: Export ffff91012f5c1000 already connecting from 192.168.204.43@tcp [ 4332.932137] Lustre: Skipped 3 previous similar messages [ 4347.352154] LustreError: 96720:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4347.358390] Lustre: 96720:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff91011ea19f80 x1875968779760512/t0(0) o38->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:0/0 lens 520/416 e 0 to 0 dl 1789067478 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4348.275571] LustreError: 98138:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4388.322448] LustreError: 98138:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 awake [ 4388.344746] Lustre: 98138:0:(service.c:2587:ptlrpc_server_handle_request()) @@@ Request took longer than estimated (20/20s); client may timeout req@ffff910107aca680 x1875968779762432/t0(0) o38->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:0/0 lens 520/416 e 0 to 0 dl 1789067519 ref 1 fl Complete:H/200/0 rc 0/0 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4388.721163] LustreError: 96718:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout id 704 sleeping for 40000ms [ 4406.577083] LustreError: 96718:0:(ldlm_lib.c:1443:target_handle_connect()) cfs_fail_timeout interrupted [ 4412.966819] Lustre: DEBUG MARKER: == replay-single test 44c: race in target handle connect ========================================================== 15:12:41 (1789067561) [ 4417.130457] LustreError: 100580:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 4417.134895] LustreError: 100580:0:(osd_handler.c:720:osd_ro()) Skipped 8 previous similar messages [ 4418.206583] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4423.316465] Lustre: Failing over lustre-MDT0000 [ 4423.582081] Lustre: server umount lustre-MDT0000 complete [ 4433.730325] Lustre: *** cfs_fail_loc=712, val=0*** [ 4433.742601] LustreError: 36709:0:(service.c:1394:ptlrpc_check_req()) @@@ Invalid replay without recovery req@ffff91013c265180 x1875968799538560/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 [ 4434.067886] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4434.069584] Lustre: lustre-MDT0000: Aborting client recovery [ 4434.075644] Lustre: Skipped 18 previous similar messages [ 4434.082215] LustreError: 101247:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 4434.087250] Lustre: 101293:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4434.094802] Lustre: 101293:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 4434.100809] Lustre: 101293:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0000: disconnect stale client 0a642e2b-1ad1-4091-83a2-560e605db3b3@ [ 4434.110161] Lustre: lustre-MDT0000: disconnecting 1 stale clients [ 4434.156944] Lustre: lustre-MDT0000-osd: cancel update llog [0x2000182d0:0x1:0x0] [ 4434.262033] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2913) [ 4434.270759] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2945) [ 4439.001063] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4447.782331] Lustre: Failing over lustre-MDT0000 [ 4448.248596] Lustre: server umount lustre-MDT0000 complete [ 4465.440183] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789067600/real 1789067600] req@ffff91013c771f80 x1875968799547648/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789067616 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4465.494360] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 24 previous similar messages [ 4475.768031] LustreError: 102221:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4475.799343] LustreError: 102221:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 4476.366126] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4476.374310] Lustre: Skipped 3 previous similar messages [ 4477.670561] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2867 to 0x240000400:2977) [ 4477.672844] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2866 to 0x280000400:2945) [ 4481.395938] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4492.789927] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4494.832553] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4504.831323] Lustre: DEBUG MARKER: == replay-single test 45: Handle failed close ============ 15:14:13 (1789067653) [ 4505.013393] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 4505.025105] Lustre: Skipped 2 previous similar messages [ 4514.845550] Lustre: DEBUG MARKER: == replay-single test 46: Don't leak file handle after open resend (3325) ========================================================== 15:14:23 (1789067663) [ 4516.175362] Lustre: *** cfs_fail_loc=122, val=2147483648*** [ 4516.177457] LustreError: 102233:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff910107af8000 x1875968779820032/t0(0) o700->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:47/0 lens 264/248 e 0 to 0 dl 1789067677 ref 1 fl Interpret:/200/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:4294967295 [ 4535.821111] Lustre: Failing over lustre-MDT0000 [ 4536.117422] Lustre: server umount lustre-MDT0000 complete [ 4554.208405] 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 [ 4554.234444] Lustre: Skipped 7 previous similar messages [ 4565.410446] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe45856c [ 4565.428555] Lustre: MGC192.168.204.143@tcp: Connection restored to 0@lo (at 0@lo) [ 4565.434992] Lustre: Skipped 8 previous similar messages [ 4571.138876] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4577.666712] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4577.681063] Lustre: Skipped 2 previous similar messages [ 4577.786858] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4577.797818] Lustre: Skipped 2 previous similar messages [ 4577.853601] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2947 to 0x280000400:2977) [ 4577.854127] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2979 to 0x240000400:3009) [ 4584.859933] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4586.900596] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4601.084267] Lustre: DEBUG MARKER: == replay-single test 47: MDS->OSC failure during precreate cleanup (2824) ========================================================== 15:15:50 (1789067750) [ 4603.968335] Lustre: Failing over lustre-OST0000 [ 4604.056435] Lustre: server umount lustre-OST0000 complete [ 4605.921638] LustreError: 36705: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. [ 4632.450143] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4643.422467] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 4645.305240] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 4719.066860] Lustre: DEBUG MARKER: == replay-single test 48: MDS->OSC failure during precreate cleanup (2824) ========================================================== 15:17:48 (1789067868) [ 4723.687231] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4726.207610] Lustre: Failing over lustre-MDT0000 [ 4726.485981] Lustre: server umount lustre-MDT0000 complete [ 4743.658590] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4743.672112] LustreError: Skipped 3 previous similar messages [ 4753.894588] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe45982e [ 4757.638093] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3030 to 0x240000400:3073) [ 4757.638741] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2998 to 0x280000400:3041) [ 4759.367940] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4834.352201] Lustre: DEBUG MARKER: == replay-single test 50: Double OSC recovery, don't LASSERT (3812) ========================================================== 15:19:43 (1789067983) [ 4836.455903] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnecting [ 4836.466405] Lustre: Skipped 2 previous similar messages [ 4850.549573] Lustre: DEBUG MARKER: == replay-single test 52: time out lock replay (3764) ==== 15:19:59 (1789067999) [ 4854.234599] Lustre: Failing over lustre-MDT0000 [ 4854.676398] Lustre: server umount lustre-MDT0000 complete [ 4881.377697] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff910005b69f80 x1875968799654528/t0(0) o250->MGC192.168.204.143@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 [ 4884.862663] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 4884.872406] LustreError: 108728:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff910105d7f480 x1875968779941376/t0(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:416/0 lens 328/344 e 0 to 0 dl 1789068046 ref 1 fl Complete:/240/0 rc 0/0 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 4886.259648] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4901.233318] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnected, waiting for 1 clients in recovery for 1:24 [ 4901.393204] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3085 to 0x240000400:3105) [ 4901.395488] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3052 to 0x280000400:3073) [ 4908.248578] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4910.105732] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4920.998427] Lustre: DEBUG MARKER: == replay-single test 53a: |X| close request while two MDC requests in flight ========================================================== 15:21:09 (1789068069) [ 4923.219714] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 4928.219216] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4930.221475] Lustre: Failing over lustre-MDT0000 [ 4930.596286] Lustre: server umount lustre-MDT0000 complete [ 4957.668610] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff910107d2ad80 x1875968799673216/t0(0) o250->MGC192.168.204.143@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 [ 4963.202579] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4964.287101] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3107 to 0x240000400:3137) [ 4964.287641] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3052 to 0x280000400:3105) [ 4973.235663] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 4975.002651] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4984.630724] Lustre: DEBUG MARKER: == replay-single test 53b: |X| open request while two MDC requests in flight ========================================================== 15:22:13 (1789068133) [ 4985.775386] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 4991.441924] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 4993.362214] Lustre: Failing over lustre-MDT0000 [ 4993.673553] Lustre: server umount lustre-MDT0000 complete [ 5018.685505] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5026.660293] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3107 to 0x240000400:3169) [ 5026.664040] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3107 to 0x280000400:3137) [ 5032.426821] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5034.101162] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5043.061896] Lustre: DEBUG MARKER: == replay-single test 53c: |X| open request and close request while two MDC requests in flight ========================================================== 15:23:12 (1789068192) [ 5044.131238] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 5048.690902] LustreError: 113247:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5048.698480] LustreError: 113247:0:(osd_handler.c:720:osd_ro()) Skipped 3 previous similar messages [ 5049.687534] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5051.629202] Lustre: Failing over lustre-MDT0000 [ 5051.946378] Lustre: server umount lustre-MDT0000 complete [ 5069.283758] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789068204/real 1789068204] req@ffff91012be21c00 x1875968799705984/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789068220 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5069.311865] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 56 previous similar messages [ 5079.469346] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe45bc93 [ 5079.939747] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5079.948250] Lustre: Skipped 6 previous similar messages [ 5080.039527] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5080.048316] Lustre: Skipped 9 previous similar messages [ 5084.657230] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5085.195299] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3139 to 0x280000400:3169) [ 5085.196353] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3107 to 0x240000400:3201) [ 5097.346939] Lustre: DEBUG MARKER: == replay-single test 53d: close reply while two MDC requests in flight ========================================================== 15:24:06 (1789068246) [ 5099.686156] Lustre: *** cfs_fail_loc=13b, val=315*** [ 5099.693678] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 5099.697086] LustreError: 113856:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff910135030a80 x1875968779988736/t257698037777(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:631/0 lens 392/456 e 0 to 0 dl 1789068261 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5103.243566] Lustre: Failing over lustre-MDT0000 [ 5103.699725] Lustre: server umount lustre-MDT0000 complete [ 5132.265531] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91013be78000 x1875968799723008/t0(0) o250->MGC192.168.204.143@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 [ 5140.117725] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5142.057085] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3203 to 0x240000400:3233) [ 5142.060331] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3139 to 0x280000400:3201) [ 5142.073481] Lustre: 115159:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff91012f282d80 x1875968779988736/t257698037777(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:673/0 lens 392/456 e 0 to 0 dl 1789068303 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5152.272529] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5153.900144] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5162.542885] Lustre: DEBUG MARKER: == replay-single test 53e: |X| open reply while two MDC requests in flight ========================================================== 15:25:11 (1789068311) [ 5163.788308] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 5163.798037] LustreError: 115158:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9101355f9f80 x1875968780002944/t261993005072(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:695/0 lens 504/448 e 0 to 0 dl 1789068325 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 5170.448915] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5172.862321] Lustre: Failing over lustre-MDT0000 [ 5173.223295] Lustre: server umount lustre-MDT0000 complete [ 5189.600366] 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 [ 5189.630373] Lustre: Skipped 17 previous similar messages [ 5199.846232] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe45c871 [ 5199.889435] Lustre: MGC192.168.204.143@tcp: Connection restored to 0@lo (at 0@lo) [ 5199.898395] Lustre: Skipped 19 previous similar messages [ 5205.737323] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5206.193670] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5206.201039] Lustre: Skipped 7 previous similar messages [ 5206.236598] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5206.249250] Lustre: Skipped 7 previous similar messages [ 5206.308327] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3139 to 0x280000400:3233) [ 5206.309595] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3235 to 0x240000400:3265) [ 5206.311404] Lustre: 116844:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff91010732b100 x1875968780002944/t261993005072(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:738/0 lens 504/2880 e 0 to 0 dl 1789068368 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 5216.739043] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5218.392121] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5228.787614] Lustre: DEBUG MARKER: == replay-single test 53f: |X| open reply and close reply while two MDC requests in flight ========================================================== 15:26:17 (1789068377) [ 5230.210262] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 5230.220314] LustreError: 116847:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff910107afb800 x1875968780017280/t266287972368(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:7/0 lens 504/448 e 0 to 0 dl 1789068392 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 5232.002650] Lustre: *** cfs_fail_loc=13b, val=315*** [ 5235.891746] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5238.060094] Lustre: Failing over lustre-MDT0000 [ 5238.396693] Lustre: server umount lustre-MDT0000 complete [ 5270.889083] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3235 to 0x240000400:3297) [ 5270.908424] Lustre: 118542:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff91013c069f80 x1875968780018048/t266287972369(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:47/0 lens 392/456 e 0 to 0 dl 1789068432 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5270.917132] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3235 to 0x280000400:3265) [ 5270.973940] Lustre: 118542:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 1 previous similar message [ 5273.195822] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5286.351965] Lustre: DEBUG MARKER: == replay-single test 53g: |X| drop open reply and close request while close and open are both in flight ========================================================== 15:27:15 (1789068435) [ 5287.580144] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 5287.583482] Lustre: Skipped 1 previous similar message [ 5287.586380] LustreError: 118540:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff910107328a80 x1875968780030080/t270582939664(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:64/0 lens 504/448 e 0 to 0 dl 1789068449 ref 1 fl Interpret:/200/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 5287.622555] LustreError: 118540:0:(ldlm_lib.c:3382:target_send_reply_msg()) Skipped 1 previous similar message [ 5289.579269] Lustre: *** cfs_fail_loc=115, val=2147483648*** [ 5289.585984] Lustre: Skipped 1 previous similar message [ 5294.231780] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5296.150698] Lustre: Failing over lustre-MDT0000 [ 5296.376289] Lustre: server umount lustre-MDT0000 complete [ 5322.721959] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff910135694000 x1875968799771776/t0(0) o250->MGC192.168.204.143@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 [ 5328.956996] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5329.217985] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3299 to 0x240000400:3329) [ 5329.242307] Lustre: 120075:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff910105d7f480 x1875968780030080/t270582939664(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:105/0 lens 504/2880 e 0 to 0 dl 1789068490 ref 1 fl Interpret:/202/0 rc 0/0 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 5329.245600] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3235 to 0x280000400:3297) [ 5340.963560] Lustre: DEBUG MARKER: == replay-single test 53h: open request and close reply while two MDC requests in flight ========================================================== 15:28:09 (1789068489) [ 5342.337127] Lustre: *** cfs_fail_loc=107, val=2147483648*** [ 5344.295446] Lustre: *** cfs_fail_loc=13b, val=315*** [ 5344.307726] Lustre: *** cfs_fail_loc=13b, val=2147483648*** [ 5344.310042] LustreError: 120079:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff91013bca5880 x1875968780042240/t274877906960(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:121/0 lens 392/456 e 0 to 0 dl 1789068506 ref 1 fl Interpret:/600/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5349.273521] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5351.717528] Lustre: Failing over lustre-MDT0000 [ 5352.012672] Lustre: server umount lustre-MDT0000 complete [ 5368.288779] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5368.310470] LustreError: Skipped 8 previous similar messages [ 5378.465263] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff910107ac8a80 x1875968799787264/t0(0) o250->MGC192.168.204.143@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 [ 5383.352271] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5383.654332] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3299 to 0x240000400:3361) [ 5383.655400] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3299 to 0x280000400:3329) [ 5383.663023] Lustre: 121542:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff91013c7b5c00 x1875968780042240/t274877906960(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:160/0 lens 392/456 e 0 to 0 dl 1789068545 ref 1 fl Interpret:/602/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 5396.529641] Lustre: DEBUG MARKER: == replay-single test 55: let MDS_CHECK_RESENT return the original return code instead of 0 ========================================================== 15:29:05 (1789068545) [ 5397.665947] Lustre: *** cfs_fail_loc=12b, val=2147483991*** [ 5397.681478] LustreError: 121539:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff91013d7d4000 x1875968780052992/t279172874255(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:174/0 lens 664/608 e 0 to 0 dl 1789068559 ref 1 fl Interpret:/600/0 rc 301/0 job:'touch.0' uid:0 gid:0 projid:0 [ 5414.262300] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnecting [ 5414.273580] Lustre: Skipped 1 previous similar message [ 5414.298153] Lustre: 121541:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff9101072a6680 x1875968780052992/t279172874255(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:191/0 lens 664/3488 e 0 to 0 dl 1789068576 ref 1 fl Interpret:/602/0 rc 0/0 job:'touch.0' uid:0 gid:0 projid:0 [ 5422.215269] Lustre: DEBUG MARKER: == replay-single test 56: don't replay a symlink open request (3440) ========================================================== 15:29:31 (1789068571) [ 5426.212382] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5428.261748] Lustre: Failing over lustre-MDT0000 [ 5428.558145] Lustre: server umount lustre-MDT0000 complete [ 5451.931908] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5456.395447] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3299 to 0x280000400:3361) [ 5456.397166] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3363 to 0x240000400:3393) [ 5462.563854] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5463.941856] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5482.696262] Lustre: DEBUG MARKER: == replay-single test 57: test recovery from llog for setattr op ========================================================== 15:30:32 (1789068632) [ 5487.779309] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5489.738049] Lustre: Failing over lustre-MDT0000 [ 5490.173469] Lustre: server umount lustre-MDT0000 complete [ 5519.841109] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9101355f8380 x1875968799826432/t0(0) o250->MGC192.168.204.143@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 [ 5525.610957] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5533.181375] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:3363 to 0x280000400:3393) [ 5533.193306] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:3363 to 0x240000400:3425) [ 5540.831435] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5542.329308] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5550.003447] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 5565.477598] Lustre: DEBUG MARKER: == replay-single test 58a: test recovery from llog for setattr op (test llog_gen_rec) ========================================================== 15:31:54 (1789068714) [ 5617.513342] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5619.981926] Lustre: Failing over lustre-MDT0000 [ 5620.092329] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.43@tcp (stopping) [ 5620.103532] Lustre: Skipped 1 previous similar message [ 5620.744529] Lustre: server umount lustre-MDT0000 complete [ 5647.330414] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe473eea [ 5652.756465] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5660.427176] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4644 to 0x280000400:4673) [ 5660.427457] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4676 to 0x240000400:4705) [ 5666.063335] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5667.749854] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5738.395228] Lustre: DEBUG MARKER: == replay-single test 58b: test replay of setxattr op ==== 15:34:46 (1789068886) [ 5743.611286] LustreError: 128386:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 5743.629434] LustreError: 128386:0:(osd_handler.c:720:osd_ro()) Skipped 7 previous similar messages [ 5744.713503] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5747.213168] Lustre: Failing over lustre-MDT0000 [ 5747.563382] Lustre: server umount lustre-MDT0000 complete [ 5766.624131] Lustre: 3304:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789068901/real 1789068901] req@ffff91010719f480 x1875968800532352/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789068917 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5766.676556] Lustre: 3304:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 79 previous similar messages [ 5777.375921] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5777.383125] Lustre: Skipped 8 previous similar messages [ 5777.464440] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5777.469462] Lustre: Skipped 8 previous similar messages [ 5782.598727] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5790.704143] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4676 to 0x240000400:4737) [ 5790.708775] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4675 to 0x280000400:4705) [ 5797.476488] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5798.940892] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5811.551199] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount FULL mgc.*.mgs_server_uuid 1475 0 [ 5813.605658] Lustre: DEBUG MARKER: mgc.*.mgs_server_uuid in FULL state after 0 sec [ 5821.854234] Lustre: DEBUG MARKER: == replay-single test 58c: resend/reconstruct setxattr op ========================================================== 15:36:10 (1789068970) [ 5828.658480] Lustre: *** cfs_fail_loc=123, val=2147483648*** [ 5847.776081] Lustre: *** cfs_fail_loc=119, val=2147483648*** [ 5847.783274] Lustre: Skipped 1 previous similar message [ 5847.786429] LustreError: 128987:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff91011140f850 x1875968782838144/t296352743435(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:624/0 lens 66040/440 e 0 to 0 dl 1789069009 ref 1 fl Interpret:/600/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 5863.290762] Lustre: 128986:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff91012be21500 x1875968782838144/t296352743435(0) o36->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:640/0 lens 66040/440 e 0 to 0 dl 1789069025 ref 1 fl Interpret:/602/0 rc 0/0 job:'setfattr.0' uid:0 gid:0 projid:0 [ 5874.150988] Lustre: DEBUG MARKER: SKIP: replay-single test_59 skipping ALWAYS excluded test 59 [ 5876.476216] Lustre: DEBUG MARKER: == replay-single test 60: test llog post recovery init vs llog unlink ========================================================== 15:37:05 (1789069025) [ 5888.348584] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 5891.566012] Lustre: Failing over lustre-MDT0000 [ 5891.992329] Lustre: server umount lustre-MDT0000 complete [ 5909.472200] 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 [ 5909.485174] Lustre: Skipped 14 previous similar messages [ 5919.717312] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91010704e300 x1875968800571904/t0(0) o250->MGC192.168.204.143@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 [ 5925.131416] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5934.376097] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5934.390224] Lustre: Skipped 17 previous similar messages [ 5934.968821] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5934.978644] Lustre: Skipped 7 previous similar messages [ 5936.827985] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 5936.842021] Lustre: Skipped 7 previous similar messages [ 5936.931232] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:4806 to 0x280000400:4833) [ 5936.947317] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:4839 to 0x240000400:4865) [ 5944.857921] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 5946.658305] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5959.168816] Lustre: DEBUG MARKER: == replay-single test 61a: test race llog recovery vs llog cleanup ========================================================== 15:38:27 (1789069107) [ 5982.852393] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 5999.093643] Lustre: Failing over lustre-OST0000 [ 5999.205882] Lustre: server umount lustre-OST0000 complete [ 6001.139423] LustreError: 36704: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. [ 6001.152499] LustreError: 36704:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 7 previous similar messages [ 6011.361605] LustreError: 6706: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. [ 6011.391835] LustreError: 6706:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 6025.967521] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6040.846033] Lustre: Failing over lustre-OST0000 [ 6040.856646] LustreError: 134055:0:(ldlm_lib.c:3038:target_stop_recovery_thread()) lustre-OST0000: Aborting recovery [ 6040.875829] Lustre: 133489:0:(ldlm_lib.c:2438:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 6040.890627] Lustre: 133489:0:(ldlm_lib.c:2438:target_recovery_overseer()) Skipped 2 previous similar messages [ 6040.901847] Lustre: 133489:0:(ldlm_lib.c:1948:abort_req_replay_queue()) @@@ aborted: req@ffff910001a51880 x1875968800623488/t0(17179870644) o6->lustre-MDT0000-mdtlov_UUID@0@lo:66/0 lens 544/0 e 2 to 0 dl 1789069206 ref 1 fl Complete:/204/ffffffff rc 0/-1 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 6040.940149] LustreError: 133489:0:(ofd_obd.c:1325:ofd_iocontrol()) lustre-OST0000: iocontrol from 'tgt_recover_0' cmd=c00866c1 _IOWR('f', 193, 8) unrecognized: rc = -25 [ 6040.948110] LustreError: lustre-OST0000-osc-MDT0000: operation ost_destroy to node 0@lo failed: rc = -19 [ 6040.980294] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 6041.056987] Lustre: server umount lustre-OST0000 complete [ 6046.180431] LustreError: 36713: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. [ 6046.191704] LustreError: 36713:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 6070.880760] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6075.040912] LustreError: 3302:0:(client.c:3449:ptlrpc_replay_interpret()) @@@ status 0, old was -19 req@ffff910005b6a680 x1875968800623488/t17179870644(17179870644) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 3 to 0 dl 1789069244 ref 2 fl Interpret:RQU/204/0 rc 0/0 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 6083.407991] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 6085.155824] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6125.934904] Lustre: DEBUG MARKER: == replay-single test 61b: test race mds llog sync vs llog cleanup ========================================================== 15:41:15 (1789069275) [ 6129.018709] Lustre: Failing over lustre-MDT0000 [ 6129.302966] Lustre: server umount lustre-MDT0000 complete [ 6147.586806] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6147.609233] LustreError: Skipped 5 previous similar messages [ 6154.913409] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6156.377902] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5249) [ 6156.379911] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5281) [ 6170.805893] Lustre: Failing over lustre-MDT0000 [ 6171.253428] Lustre: server umount lustre-MDT0000 complete [ 6199.266733] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91013be78000 x1875968800771840/t0(0) o250->MGC192.168.204.143@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 [ 6205.398203] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6212.545871] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5234 to 0x280000400:5281) [ 6212.549227] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5266 to 0x240000400:5313) [ 6219.545424] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 6222.650932] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6236.096821] Lustre: DEBUG MARKER: == replay-single test 61c: test race mds llog sync vs llog cleanup ========================================================== 15:43:04 (1789069384) [ 6252.270549] Lustre: Failing over lustre-OST0000 [ 6253.431305] Lustre: lustre-OST0000: Not available for connect from 192.168.204.43@tcp (stopping) [ 6253.542067] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 6254.363510] Lustre: server umount lustre-OST0000 complete [ 6256.101343] LustreError: 127970: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. [ 6256.117309] LustreError: 127970:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 3 previous similar messages [ 6288.293294] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6298.879862] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 6300.809974] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6311.956480] Lustre: DEBUG MARKER: == replay-single test 61d: error in llog_setup should cleanup the llog context correctly ========================================================== 15:44:21 (1789069461) [ 6314.239222] Lustre: Failing over lustre-MDT0000 [ 6314.664613] Lustre: server umount lustre-MDT0000 complete [ 6325.343473] Lustre: *** cfs_fail_loc=605, val=0*** [ 6325.346491] LustreError: 140066:0:(llog_obd.c:192:llog_setup()) MGS: ctxt 0 lop_setup=ffffffffc121c360 failed: rc = -95 [ 6325.352738] LustreError: 140066:0:(obd_config.c:845:class_setup()) setup MGS failed (-95) [ 6325.357389] LustreError: 140066:0:(obd_mount.c:259:lustre_start_simple()) MGS setup error -95 [ 6325.361993] LustreError: 140066:0:(tgt_mount.c:116:server_deregister_mount()) MGS not registered [ 6325.367951] LustreError: Failed to start MGS 'MGS' (-95). Is the 'mgs' module loaded? [ 6325.377515] LustreError: 140066:0:(tgt_mount.c:2128:server_put_super()) no obd lustre-MDT0000 [ 6325.464733] Lustre: server umount lustre-MDT0000 complete [ 6325.472512] LustreError: 140066:0:(super25.c:179:lustre_fill_super()) llite: Unable to mount : rc = -95 [ 6342.131139] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe4b3622 [ 6348.082828] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6356.028105] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5283 to 0x280000400:5313) [ 6356.028984] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5315 to 0x240000400:5345) [ 6357.805753] Lustre: DEBUG MARKER: == replay-single test 62: don't mis-drop resent replay === 15:45:06 (1789069506) [ 6361.188917] LustreError: 141121:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 6361.196060] LustreError: 141121:0:(osd_handler.c:720:osd_ro()) Skipped 2 previous similar messages [ 6362.443835] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6366.932343] Lustre: Failing over lustre-MDT0000 [ 6367.202911] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6367.210931] Lustre: Skipped 1 previous similar message [ 6367.361644] Lustre: server umount lustre-MDT0000 complete [ 6388.704201] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789069523/real 1789069523] req@ffff91010704e300 x1875968800819200/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789069539 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6388.773647] Lustre: 3303:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 43 previous similar messages [ 6389.720683] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6389.725541] Lustre: Skipped 7 previous similar messages [ 6389.795362] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 6389.804438] Lustre: Skipped 7 previous similar messages [ 6395.616342] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6396.854707] Lustre: *** cfs_fail_loc=707, val=0*** [ 6413.209238] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnected, waiting for 1 clients in recovery for 0:53 [ 6414.188117] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5327 to 0x280000400:5345) [ 6414.191528] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5358 to 0x240000400:5377) [ 6421.489634] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 6423.736267] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6434.031747] Lustre: DEBUG MARKER: == replay-single test 65a: AT: verify early replies ====== 15:46:23 (1789069583) [ 6467.055715] LustreError: 141787:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff910105d79f80 x1875968783717248/t0(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:488/0 lens 664/0 e 0 to 0 dl 1789069628 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6467.111677] LustreError: 141787:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 11000ms [ 6478.160620] LustreError: 141787:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6478.212309] LustreError: 141789:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff91010732b480 x1875968783718272/t0(0) o35->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:506/0 lens 392/0 e 0 to 0 dl 1789069646 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6482.248858] LustreError: 141783:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff9101072a4380 x1875968783724416/t0(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:543/0 lens 576/0 e 0 to 0 dl 1789069683 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'unlinkmany.0' uid:0 gid:0 projid:0 [ 6482.274680] LustreError: 141783:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 27 previous similar messages [ 6486.230098] LustreError: 14683:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff91012f284000 x1875968800848640/t0(0) o6->lustre-MDT0000-mdtlov_UUID@0@lo:508/0 lens 544/0 e 0 to 0 dl 1789069648 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-syn-1-0.0' uid:0 gid:0 projid:4294967295 [ 6486.315681] LustreError: 14683:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 28 previous similar messages [ 6501.398606] Lustre: DEBUG MARKER: == replay-single test 65b: AT: verify early replies on packed reply / bulk ========================================================== 15:47:30 (1789069650) [ 6533.640233] LustreError: 35456:0:(tgt_handler.c:2830:tgt_brw_write()) cfs_fail_timeout id 224 sleeping for 11000ms [ 6544.728195] LustreError: 35456:0:(tgt_handler.c:2830:tgt_brw_write()) cfs_fail_timeout id 224 awake [ 6555.969924] Lustre: DEBUG MARKER: == replay-single test 66a: AT: verify MDT service time adjusts with no early replies ========================================================== 15:48:24 (1789069704) [ 6586.016775] LustreError: 141783:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff91000a2f5c00 x1875968783741312/t0(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:607/0 lens 576/0 e 0 to 0 dl 1789069747 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6586.070324] LustreError: 141783:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 5000ms [ 6591.088405] LustreError: 141783:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6598.192031] LustreError: 36705:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff91011e8eea00 x1875968800872832/t0(0) o6->lustre-MDT0000-mdtlov_UUID@0@lo:619/0 lens 544/0 e 0 to 0 dl 1789069759 ref 1 fl Interpret:/200/ffffffff rc 0/-1 job:'osp-syn-1-0.0' uid:0 gid:0 projid:4294967295 [ 6598.231452] LustreError: 36705:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 117 previous similar messages [ 6603.993279] LustreError: 141783:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6626.710739] Lustre: DEBUG MARKER: == replay-single test 66b: AT: verify net latency adjusts ========================================================== 15:49:35 (1789069775) [ 6724.066435] Lustre: DEBUG MARKER: == replay-single test 67a: AT: verify slow request processing doesn't induce reconnects ========================================================== 15:51:12 (1789069872) [ 6754.423815] LustreError: 142201:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff910110799880 x1875968783816320/t0(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:21/0 lens 576/0 e 0 to 0 dl 1789069916 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 projid:0 [ 6754.462707] LustreError: 142201:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 99 previous similar messages [ 6754.472560] LustreError: 142201:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 6754.483606] LustreError: 142201:0:(service.c:2564:ptlrpc_server_handle_request()) Skipped 1 previous similar message [ 6754.920143] LustreError: 142201:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6770.625204] LustreError: 143301:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a sleeping for 400ms [ 6770.649618] LustreError: 143301:0:(service.c:2564:ptlrpc_server_handle_request()) Skipped 36 previous similar messages [ 6771.080227] LustreError: 143301:0:(service.c:2564:ptlrpc_server_handle_request()) cfs_fail_timeout id 50a awake [ 6771.086915] LustreError: 143301:0:(service.c:2564:ptlrpc_server_handle_request()) Skipped 36 previous similar messages [ 6786.600967] LustreError: 142201:0:(service.c:2563:ptlrpc_server_handle_request()) @@@ HIT req@ffff91012b76aa00 x1875968783833984/t0(0) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:53/0 lens 576/0 e 0 to 0 dl 1789069948 ref 1 fl Interpret:/600/ffffffff rc 0/-1 job:'unlinkmany.0' uid:0 gid:0 projid:0 [ 6786.630099] LustreError: 142201:0:(service.c:2563:ptlrpc_server_handle_request()) Skipped 75 previous similar messages [ 6807.223993] Lustre: DEBUG MARKER: == replay-single test 67b: AT: verify instant slowdown doesn't induce reconnects ========================================================== 15:52:36 (1789069956) [ 6843.582765] Lustre: DEBUG MARKER: phase 2 [ 6856.797323] Lustre: DEBUG MARKER: == replay-single test 68: AT: verify slowing locks ======= 15:53:25 (1789070005) [ 6944.164538] Lustre: DEBUG MARKER: == replay-single test 70a: check multi client t-f ======== 15:54:53 (1789070093) [ 6946.534498] Lustre: DEBUG MARKER: SKIP: replay-single test_70a Need two or more clients, have 1 [ 6948.537709] Lustre: DEBUG MARKER: == replay-single test 70b: dbench 1mdts recovery; 1 clients ========================================================== 15:54:57 (1789070097) [ 6954.639951] Lustre: DEBUG MARKER: Started rundbench load pid=128946 ... [ 6962.069000] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 6965.120394] Lustre: DEBUG MARKER: test_70b fail mds1 1 times [ 6967.018428] Lustre: Failing over lustre-MDT0000 [ 6967.126532] Lustre: lustre-MDT0000: Not available for connect from 192.168.204.43@tcp (stopping) [ 6967.140730] Lustre: Skipped 1 previous similar message [ 6967.325082] Lustre: server umount lustre-MDT0000 complete [ 6985.899932] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6985.912715] LustreError: Skipped 3 previous similar messages [ 6986.407085] 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 [ 6986.427034] Lustre: Skipped 11 previous similar messages [ 6991.694592] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6991.852051] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 6991.861656] Lustre: Skipped 12 previous similar messages [ 6992.864565] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789070127/real 1789070127] req@ffff91011e8e4000 x1875968800985600/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789070143 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6992.901349] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 7005.042990] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 7005.048429] Lustre: Skipped 7 previous similar messages [ 7006.028520] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 7006.044625] Lustre: Skipped 7 previous similar messages [ 7006.117241] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5479 to 0x240000400:5505) [ 7006.121096] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5425 to 0x280000400:5441) [ 7013.679308] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7015.907620] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7022.634439] LustreError: 150105:0:(osd_handler.c:720:osd_ro()) lustre-MDT0000: *** setting device osd-zfs read-only *** [ 7022.646730] LustreError: 150105:0:(osd_handler.c:720:osd_ro()) Skipped 1 previous similar message [ 7023.895944] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7026.852620] Lustre: DEBUG MARKER: test_70b fail mds1 2 times [ 7028.820975] Lustre: Failing over lustre-MDT0000 [ 7029.184286] Lustre: server umount lustre-MDT0000 complete [ 7049.171881] LustreError: 150748: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. [ 7049.191730] LustreError: 150748:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 10 previous similar messages [ 7049.742595] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7049.746537] Lustre: Skipped 1 previous similar message [ 7049.797432] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 7049.806430] Lustre: Skipped 1 previous similar message [ 7054.787483] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7066.634789] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:5463 to 0x280000400:5505) [ 7066.636224] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:5526 to 0x240000400:5569) [ 7074.017221] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7076.015973] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7109.251422] Lustre: DEBUG MARKER: == replay-single test 70c: tar 1mdts recovery ============ 15:57:38 (1789070258) [ 7235.306095] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7247.650907] Lustre: DEBUG MARKER: test_70c fail mds1 1 times [ 7249.671783] Lustre: Failing over lustre-MDT0000 [ 7249.999357] Lustre: server umount lustre-MDT0000 complete [ 7277.490728] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7281.088620] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6143 to 0x240000400:6177) [ 7281.089417] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6079 to 0x280000400:6113) [ 7288.459068] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7290.409987] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7354.045269] Lustre: DEBUG MARKER: == replay-single test 70d: mkdir/rmdir striped dir 1mdts recovery ========================================================== 16:01:42 (1789070502) [ 7355.919344] Lustre: DEBUG MARKER: SKIP: replay-single test_70d needs >= 2 MDTs [ 7357.945332] Lustre: DEBUG MARKER: == replay-single test 70e: rename cross-MDT with random fails ========================================================== 16:01:47 (1789070507) [ 7359.617605] Lustre: DEBUG MARKER: SKIP: replay-single test_70e needs >= 2 MDTs [ 7361.749739] Lustre: DEBUG MARKER: == replay-single test 70f: OSS O_DIRECT recovery with 1 clients ========================================================== 16:01:50 (1789070510) [ 7371.210060] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7374.584381] Lustre: DEBUG MARKER: test_70f failing OST 1 times [ 7376.718699] Lustre: Failing over lustre-OST0000 [ 7376.855573] Lustre: server umount lustre-OST0000 complete [ 7377.819936] LustreError: 36704:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7403.852155] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7415.719172] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7418.095059] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7432.664302] Lustre: DEBUG MARKER: == replay-single test 71a: mkdir/rmdir striped dir with 2 mdts recovery ========================================================== 16:03:00 (1789070580) [ 7435.165231] Lustre: DEBUG MARKER: SKIP: replay-single test_71a needs >= 2 MDTs [ 7437.068641] Lustre: DEBUG MARKER: == replay-single test 73a: open(O_CREAT), unlink, replay, reconnect before open replay, close ========================================================== 16:03:06 (1789070586) [ 7442.035551] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7445.953966] Lustre: Failing over lustre-MDT0000 [ 7446.236205] Lustre: server umount lustre-MDT0000 complete [ 7476.090421] Lustre: *** cfs_fail_loc=302, val=2147483648*** [ 7480.454370] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7491.463782] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnected, waiting for 1 clients in recovery for 0:55 [ 7491.878634] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6212 to 0x280000400:6241) [ 7491.881276] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6276 to 0x240000400:6305) [ 7499.271561] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7500.666593] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7511.689935] Lustre: DEBUG MARKER: == replay-single test 73b: open(O_CREAT), unlink, replay, reconnect at open_replay reply, close ========================================================== 16:04:20 (1789070660) [ 7518.195542] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 7521.628409] Lustre: Failing over lustre-MDT0000 [ 7521.869455] Lustre: server umount lustre-MDT0000 complete [ 7557.226835] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7563.213570] Lustre: *** cfs_fail_loc=157, val=2147483648*** [ 7563.216583] LustreError: 157959:0:(ldlm_lib.c:3382:target_send_reply_msg()) @@@ dropping reply req@ffff9101113d2a00 x1875968789794688/t335007449091(335007449091) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:74/0 lens 592/608 e 0 to 0 dl 1789070724 ref 1 fl Interpret:/604/0 rc 301/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 7578.527612] Lustre: lustre-MDT0000: Client 0a642e2b-1ad1-4091-83a2-560e605db3b3 (at 192.168.204.43@tcp) reconnected, waiting for 1 clients in recovery for 0:54 [ 7578.576623] Lustre: 157959:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff91012c81a300 x1875968789794688/t335007449091(335007449091) o101->0a642e2b-1ad1-4091-83a2-560e605db3b3@192.168.204.43@tcp:90/0 lens 592/3488 e 0 to 0 dl 1789070740 ref 1 fl Interpret:/606/0 rc 0/0 job:'multiop.0' uid:0 gid:0 projid:0 [ 7578.791098] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6212 to 0x280000400:6273) [ 7578.805884] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6307 to 0x240000400:6337) [ 7585.950925] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7588.011231] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7598.223529] Lustre: DEBUG MARKER: == replay-single test 74: Ensure applications don't fail waiting for OST recovery ========================================================== 16:05:47 (1789070747) [ 7603.128396] Lustre: Failing over lustre-OST0000 [ 7603.268158] Lustre: server umount lustre-OST0000 complete [ 7604.710762] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7604.723074] 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 [ 7604.733649] Lustre: Skipped 10 previous similar messages [ 7604.748023] LustreError: 14683: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. [ 7604.765742] LustreError: 14683:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 7 previous similar messages [ 7609.019239] Lustre: Failing over lustre-MDT0000 [ 7609.517486] Lustre: server umount lustre-MDT0000 complete [ 7628.000233] Lustre: 3304:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789070762/real 1789070762] req@ffff91012ba6dc00 x1875968801778688/t0(0) o400->MGC192.168.204.143@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1789070778 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 7628.038103] Lustre: 3304:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 35 previous similar messages [ 7628.043796] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7628.054627] LustreError: Skipped 4 previous similar messages [ 7637.410779] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff91012b7b0000 x1875968801780096/t0(0) o250->MGC192.168.204.143@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 [ 7637.445112] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) Skipped 1 previous similar message [ 7637.840397] LustreError: 6706: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. [ 7637.872327] LustreError: 6706:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 1 previous similar message [ 7638.285496] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6212 to 0x280000400:6305) [ 7638.953147] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 7638.969071] Lustre: Skipped 10 previous similar messages [ 7643.583710] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7652.304232] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 7652.308567] Lustre: Skipped 5 previous similar messages [ 7652.315916] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 7652.324238] Lustre: Skipped 4 previous similar messages [ 7653.657113] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 7653.671314] Lustre: Skipped 5 previous similar messages [ 7653.676161] Lustre: lustre-OST0000: Denying connection for new client d798975d-156a-45a1-8fc0-f8e80632f0f4 (at 192.168.204.43@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 7653.702820] Lustre: Skipped 11 previous similar messages [ 7657.548413] Lustre: lustre-OST0000: Recovery over after 0:04, of 1 clients 1 recovered and 0 were evicted. [ 7657.559141] Lustre: Skipped 5 previous similar messages [ 7657.576635] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6307 to 0x240000400:6369) [ 7659.978829] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7671.618898] Lustre: DEBUG MARKER: == replay-single test 80a: DNE: create remote dir, drop update rep from MDT0, fail MDT0 ========================================================== 16:07:00 (1789070820) [ 7673.191154] Lustre: DEBUG MARKER: SKIP: replay-single test_80a needs >= 2 MDTs [ 7675.355514] Lustre: DEBUG MARKER: == replay-single test 80b: DNE: create remote dir, drop update rep from MDT0, fail MDT1 ========================================================== 16:07:04 (1789070824) [ 7677.006632] Lustre: DEBUG MARKER: SKIP: replay-single test_80b needs >= 2 MDTs [ 7679.169752] Lustre: DEBUG MARKER: == replay-single test 80c: DNE: create remote dir, drop update rep from MDT1, fail MDT[0,1] ========================================================== 16:07:08 (1789070828) [ 7680.598934] Lustre: DEBUG MARKER: SKIP: replay-single test_80c needs >= 2 MDTs [ 7682.932060] Lustre: DEBUG MARKER: == replay-single test 80d: DNE: create remote dir, drop update rep from MDT1, fail 2 MDTs ========================================================== 16:07:11 (1789070831) [ 7684.772671] Lustre: DEBUG MARKER: SKIP: replay-single test_80d needs >= 2 MDTs [ 7686.928667] Lustre: DEBUG MARKER: == replay-single test 80e: DNE: create remote dir, drop MDT1 rep, fail MDT0 ========================================================== 16:07:15 (1789070835) [ 7689.148531] Lustre: DEBUG MARKER: SKIP: replay-single test_80e needs >= 2 MDTs [ 7691.605786] Lustre: DEBUG MARKER: == replay-single test 80f: DNE: create remote dir, drop MDT1 rep, fail MDT1 ========================================================== 16:07:20 (1789070840) [ 7694.126297] Lustre: DEBUG MARKER: SKIP: replay-single test_80f needs >= 2 MDTs [ 7696.855413] Lustre: DEBUG MARKER: == replay-single test 80g: DNE: create remote dir, drop MDT1 rep, fail MDT0, then MDT1 ========================================================== 16:07:25 (1789070845) [ 7698.872686] Lustre: DEBUG MARKER: SKIP: replay-single test_80g needs >= 2 MDTs [ 7701.181713] Lustre: DEBUG MARKER: == replay-single test 80h: DNE: create remote dir, drop MDT1 rep, fail 2 MDTs ========================================================== 16:07:29 (1789070849) [ 7703.395869] Lustre: DEBUG MARKER: SKIP: replay-single test_80h needs >= 2 MDTs [ 7706.123471] Lustre: DEBUG MARKER: == replay-single test 81a: DNE: unlink remote dir, drop MDT0 update rep, fail MDT1 ========================================================== 16:07:34 (1789070854) [ 7708.507711] Lustre: DEBUG MARKER: SKIP: replay-single test_81a needs >= 2 MDTs [ 7710.935727] Lustre: DEBUG MARKER: == replay-single test 81b: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0 ========================================================== 16:07:39 (1789070859) [ 7713.171288] Lustre: DEBUG MARKER: SKIP: replay-single test_81b needs >= 2 MDTs [ 7716.296487] Lustre: DEBUG MARKER: == replay-single test 81c: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0,MDT1 ========================================================== 16:07:44 (1789070864) [ 7718.352386] Lustre: DEBUG MARKER: SKIP: replay-single test_81c needs >= 2 MDTs [ 7720.864711] Lustre: DEBUG MARKER: == replay-single test 81d: DNE: unlink remote dir, drop MDT0 update reply, fail 2 MDTs ========================================================== 16:07:49 (1789070869) [ 7723.566598] Lustre: DEBUG MARKER: SKIP: replay-single test_81d needs >= 2 MDTs [ 7726.298421] Lustre: DEBUG MARKER: == replay-single test 81e: DNE: unlink remote dir, drop MDT1 req reply, fail MDT0 ========================================================== 16:07:54 (1789070874) [ 7728.816295] Lustre: DEBUG MARKER: SKIP: replay-single test_81e needs >= 2 MDTs [ 7732.007830] Lustre: DEBUG MARKER: == replay-single test 81f: DNE: unlink remote dir, drop MDT1 req reply, fail MDT1 ========================================================== 16:08:00 (1789070880) [ 7734.271627] Lustre: DEBUG MARKER: SKIP: replay-single test_81f needs >= 2 MDTs [ 7737.095757] Lustre: DEBUG MARKER: == replay-single test 81g: DNE: unlink remote dir, drop req reply, fail M0, then M1 ========================================================== 16:08:05 (1789070885) [ 7739.161320] Lustre: DEBUG MARKER: SKIP: replay-single test_81g needs >= 2 MDTs [ 7742.092157] Lustre: DEBUG MARKER: == replay-single test 81h: DNE: unlink remote dir, drop request reply, fail 2 MDTs ========================================================== 16:08:10 (1789070890) [ 7744.283213] Lustre: DEBUG MARKER: SKIP: replay-single test_81h needs >= 2 MDTs [ 7746.886267] Lustre: DEBUG MARKER: == replay-single test 84a: stale open during export disconnect ========================================================== 16:08:15 (1789070895) [ 7749.239494] Lustre: 162605:0:(genops.c:1773:obd_export_evict_by_uuid()) lustre-MDT0000: evicting d798975d-156a-45a1-8fc0-f8e80632f0f4 at adminstrative request [ 7759.205468] Lustre: DEBUG MARKER: == replay-single test 85a: check the cancellation of unused locks during recovery(IBITS) ========================================================== 16:08:28 (1789070908) [ 7768.516677] Lustre: Failing over lustre-MDT0000 [ 7769.102776] Lustre: server umount lustre-MDT0000 complete [ 7798.764499] Lustre: Evicted from MGS (at 0@lo) after server handle changed from 0x0 to 0x668c9efbfe51b3b4 [ 7805.005269] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7812.569777] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6357 to 0x280000400:6401) [ 7812.570084] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6421 to 0x240000400:6465) [ 7819.711502] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 7821.694752] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 7831.935614] Lustre: DEBUG MARKER: == replay-single test 85b: check the cancellation of unused locks during recovery(EXTENT) ========================================================== 16:09:40 (1789070980) [ 7850.440436] Lustre: Failing over lustre-OST0000 [ 7850.597034] Lustre: server umount lustre-OST0000 complete [ 7851.912921] LustreError: 36702:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0000: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7851.944234] LustreError: 36702:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 4 previous similar messages [ 7854.049114] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7879.944475] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7890.588650] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7892.771213] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7903.669749] Lustre: DEBUG MARKER: == replay-single test 86: umount server after clear nid_stats should not hit LBUG ========================================================== 16:10:52 (1789071052) [ 7910.350759] Lustre: Failing over lustre-MDT0000 [ 7911.012478] Lustre: server umount lustre-MDT0000 complete [ 7919.118332] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6357 to 0x280000400:6433) [ 7919.131420] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6566 to 0x240000400:6593) [ 7923.995895] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7934.087341] Lustre: DEBUG MARKER: == replay-single test 87a: write replay ================== 16:11:23 (1789071083) [ 7938.376366] LustreError: 167047:0:(osd_handler.c:720:osd_ro()) lustre-OST0000: *** setting device osd-zfs read-only *** [ 7938.381987] LustreError: 167047:0:(osd_handler.c:720:osd_ro()) Skipped 4 previous similar messages [ 7939.537928] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 7943.357065] Lustre: Failing over lustre-OST0000 [ 7943.434023] Lustre: server umount lustre-OST0000 complete [ 7944.673676] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 7971.110707] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7984.165215] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 7986.013699] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 7998.493210] Lustre: DEBUG MARKER: == replay-single test 87b: write replay with changed data (checksum resend) ========================================================== 16:12:26 (1789071146) [ 8004.206246] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 8009.304245] Lustre: Failing over lustre-OST0000 [ 8009.430811] Lustre: server umount lustre-OST0000 complete [ 8009.708289] LustreError: 6708: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. [ 8009.726757] LustreError: 6708:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 15 previous similar messages [ 8031.484277] LustreError: lustre-OST0000: BAD WRITE CHECKSUM: from 12345-192.168.204.43@tcp inode [0x2000284a1:0x5:0x0] object 0x240000400:6594 extent [0-1048575]: client csum 46b90663, server csum 5a6906ed [ 8036.919186] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8048.349756] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 8049.803310] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 8059.430983] Lustre: DEBUG MARKER: == replay-single test 88: MDS should not assign same objid to different files ========================================================== 16:13:28 (1789071208) [ 8063.994585] Lustre: DEBUG MARKER: ost1 REPLAY BARRIER on lustre-OST0000 [ 8067.891168] Lustre: DEBUG MARKER: mds1 REPLAY BARRIER on lustre-MDT0000 [ 8074.598837] Lustre: Failing over lustre-MDT0000 [ 8074.885258] Lustre: server umount lustre-MDT0000 complete [ 8079.401271] LustreError: 36711:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789071230 with bad export cookie 7389455893748902556 [ 8089.584772] Lustre: Failing over lustre-OST0000 [ 8089.638921] Lustre: server umount lustre-OST0000 complete [ 8124.320974] LustreError: 3302:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff910005465500 x1875968801910400/t0(0) o250->MGC192.168.204.143@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 [ 8130.895643] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8136.697380] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6474 to 0x280000400:6497) [ 8157.261099] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6595 to 0x240000400:6625) [ 8159.984288] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8179.516904] Lustre: DEBUG MARKER: == replay-single test 89: no disk space leak on late ost connection ========================================================== 16:15:28 (1789071328) [ 8200.729687] Lustre: Failing over lustre-OST0000 [ 8200.857539] Lustre: server umount lustre-OST0000 complete [ 8203.232448] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 8207.808945] Lustre: Failing over lustre-MDT0000 [ 8208.222446] Lustre: server umount lustre-MDT0000 complete [ 8224.716973] 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 [ 8224.743079] Lustre: Skipped 10 previous similar messages [ 8229.792773] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1789071364/real 1789071364] req@ffff910135f5f100 x1875968801936896/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1789071380 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 8229.825898] Lustre: 3306:0:(client.c:2504:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 8237.325634] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6474 to 0x280000400:6529) [ 8240.538332] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8249.765137] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 8249.775875] Lustre: Skipped 11 previous similar messages [ 8255.683123] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8258.558904] Lustre: lustre-OST0000: Denying connection for new client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 8258.576241] Lustre: Skipped 1 previous similar message [ 8279.423587] Lustre: lustre-OST0000: Denying connection for new client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:40 [ 8279.465863] Lustre: Skipped 3 previous similar messages [ 8315.250514] Lustre: lustre-OST0000: Denying connection for new client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp), waiting for 2 known clients (1 recovered, 0 in progress, and 0 evicted) to recover in 0:04 [ 8315.278150] Lustre: Skipped 6 previous similar messages [ 8319.503103] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 8319.510428] Lustre: 174952:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client e81cf8dd-31e7-4e1a-85a4-42dede9302d4@ [ 8319.535691] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 8319.604389] Lustre: lustre-OST0000: Recovery over after 1:10, of 2 clients 1 recovered and 1 was evicted. [ 8319.617526] Lustre: Skipped 7 previous similar messages [ 8319.634858] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6636 to 0x240000400:6657) [ 8323.713696] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 55 sec [ 8340.058985] Lustre: DEBUG MARKER: free_before: 7520256 free_after: 7520256 [ 8346.869662] Lustre: DEBUG MARKER: == replay-single test 90: lfs find identifies the missing striped file segments ========================================================== 16:18:16 (1789071496) [ 8352.206601] Lustre: Failing over lustre-OST0001 [ 8352.229755] Lustre: lustre-OST0001: Not available for connect from 0@lo (stopping) [ 8352.293748] Lustre: server umount lustre-OST0001 complete [ 8356.261648] LustreError: 36712:0:(ldlm_lib.c:1199:target_handle_connect()) lustre-OST0001: not available for connect from 192.168.204.43@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8356.296211] LustreError: 36712:0:(ldlm_lib.c:1199:target_handle_connect()) Skipped 39 previous similar messages [ 8372.948085] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 8372.953583] Lustre: Skipped 9 previous similar messages [ 8372.968304] Lustre: lustre-OST0001: in recovery but waiting for the first client to connect [ 8372.987227] Lustre: Skipped 8 previous similar messages [ 8374.838906] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 8374.847374] Lustre: Skipped 8 previous similar messages [ 8380.618884] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8392.454599] Lustre: DEBUG MARKER: == replay-single test 93a: replay + reconnect ============ 16:19:01 (1789071541) [ 8397.167104] Lustre: Failing over lustre-OST0000 [ 8397.192439] LustreError: 177579:0:(ldlm_resource.c:1207:ldlm_resource_complain()) filter-lustre-OST0000_UUID: namespace resource [0x240000400:0x1a04:0x0].0x0 (ffff910107c24d00) refcount nonzero (2) after lock cleanup; forcing cleanup. [ 8398.819409] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 8399.378273] Lustre: server umount lustre-OST0000 complete [ 8419.969740] LustreError: 178034:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 40000ms [ 8419.984917] LustreError: 178034:0:(ldlm_lib.c:2939:target_recovery_thread()) Skipped 81 previous similar messages [ 8425.953108] Lustre: *** cfs_fail_loc=715, val=40*** [ 8426.162725] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8435.594905] Lustre: lustre-OST0000: Client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp) reconnected, waiting for 2 clients in recovery for 1:24 [ 8436.194534] Lustre: lustre-OST0000: Client lustre-MDT0000-mdtlov_UUID (at 0@lo) reconnected, waiting for 2 clients in recovery for 1:24 [ 8441.831843] Lustre: *** cfs_fail_loc=715, val=40*** [ 8441.837145] Lustre: Skipped 1 previous similar message [ 8442.851579] Lustre: *** cfs_fail_loc=715, val=40*** [ 8451.954523] Lustre: lustre-OST0000: Client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp) reconnected, waiting for 2 clients in recovery for 1:08 [ 8458.209767] Lustre: *** cfs_fail_loc=715, val=40*** [ 8460.065501] LustreError: 178034:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 8460.092469] LustreError: 178034:0:(ldlm_lib.c:2939:target_recovery_thread()) Skipped 81 previous similar messages [ 8468.827715] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid 1475 0 [ 8470.660304] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 8480.912178] Lustre: DEBUG MARKER: == replay-single test 93b: replay + reconnect on mds ===== 16:20:30 (1789071630) [ 8485.896959] Lustre: Failing over lustre-MDT0000 [ 8486.221145] Lustre: server umount lustre-MDT0000 complete [ 8504.471670] LustreError: MGC192.168.204.143@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8504.480524] LustreError: Skipped 4 previous similar messages [ 8509.894651] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8513.950074] LustreError: 179638:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 sleeping for 80000ms [ 8520.161571] Lustre: *** cfs_fail_loc=715, val=80*** [ 8520.167285] Lustre: Skipped 1 previous similar message [ 8529.266628] Lustre: lustre-MDT0000: Client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp) reconnected, waiting for 1 clients in recovery for 0:54 [ 8529.285397] Lustre: Skipped 1 previous similar message [ 8535.520907] Lustre: *** cfs_fail_loc=715, val=80*** [ 8545.656945] Lustre: lustre-MDT0000: Client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp) reconnected, waiting for 1 clients in recovery for 0:37 [ 8551.904360] Lustre: *** cfs_fail_loc=715, val=80*** [ 8562.034268] Lustre: lustre-MDT0000: Client 11b1f85c-79c7-471a-9a7f-785d1588d5a0 (at 192.168.204.43@tcp) reconnected, waiting for 1 clients in recovery for 0:21 [ 8593.779764] Lustre: lustre-MDT0000: Recovery already passed deadline 0:10. If you do not want to wait more, you may force taget eviction via 'lctl --device lustre-MDT0000 abort_recovery. [ 8593.960268] LustreError: 179638:0:(ldlm_lib.c:2939:target_recovery_thread()) cfs_fail_timeout id 715 awake [ 8594.002757] Lustre: 179638:0:(ldlm_lib.c:2985:target_recovery_thread()) too long recovery - read logs [ 8594.008578] LustreError: dumping log to /tmp/lustre-log.1789071744.179638 [ 8594.255947] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:6671 to 0x240000400:6689) [ 8594.258801] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:6542 to 0x280000400:6561) [ 8601.238676] Lustre: DEBUG MARKER: oleg443-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid 1475 0 [ 8603.844907] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 8613.823576] Lustre: DEBUG MARKER: == replay-single test complete, duration 8324 sec ======== 16:22:42 (1789071762) [ 8616.036745] Lustre: DEBUG MARKER: === replay-single: start cleanup 16:22:44 (1789071764) === [ 8628.255240] Lustre: DEBUG MARKER: === replay-single: finish cleanup 16:22:57 (1789071777) === [ 8658.410868] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8658.425892] Lustre: Skipped 1 previous similar message [ 8658.858734] Lustre: server umount lustre-MDT0000 complete [ 8663.683983] LustreError: 8526:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1789071814 with bad export cookie 7389455893748915079 [ 8663.716440] LustreError: 8526:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 8663.832460] Lustre: server umount lustre-OST0000 complete [ 8668.680058] Lustre: server umount lustre-OST0001 complete [ 8684.274569] Lustre: DEBUG MARKER: oleg443-server.virtnet: executing unload_modules_local [ 8687.922947] Key type lgssc unregistered [ 8688.216460] LNet: 181763:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8688.223353] LNetError: 181763:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 8688.241040] LNet: Removed LNI 192.168.204.143@tcp [ 8689.093621] Key type .llcrypt unregistered [ 8689.098698] Key type ._llcrypt unregistered