[ 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-0x00000000bffd9fff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffda000-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.16.2-1.fc38 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 530378438 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 = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f5b50-0x000f5b5f] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5970 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1BB7 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1A53 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001A13 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1AC7 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1B57 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1B8F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1a53-0xbffe1ac6] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1a52] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1ac7-0xbffe1b56] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1b57-0xbffe1b8e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1b8f-0xbffe1bb6] [ 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 2544MB 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-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 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 0xbffda000-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: 1059618 [ 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: 2829700K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001018] APIC: Switch to symmetric I/O mode setup [ 0.003334] x2apic enabled [ 0.004010] Switched APIC routing to physical x2apic. [ 0.005016] kvm-guest: setup PV IPIs [ 0.007749] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008032] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009021] pid_max: default: 32768 minimum: 301 [ 0.010187] LSM: Security Framework initializing [ 0.012084] Yama: becoming mindful. [ 0.013095] SELinux: Initializing. [ 0.014000] *** VALIDATE selinux *** [ 0.029404] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.036329] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.038149] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.039126] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.040129] *** VALIDATE tmpfs *** [ 0.041578] *** VALIDATE proc *** [ 0.043122] *** VALIDATE cgroup *** [ 0.044000] *** VALIDATE cgroup2 *** [ 0.044320] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.045160] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.046009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.047031] Spectre V2 : User space: Vulnerable [ 0.048006] Speculative Store Bypass: Vulnerable [ 0.051380] debug: unmapping init [mem 0xffffffffbb659000-0xffffffffbb660fff] [ 0.053753] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.054700] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.055023] ... version: 2 [ 0.056010] ... bit width: 48 [ 0.057011] ... generic registers: 4 [ 0.058015] ... value mask: 0000ffffffffffff [ 0.059026] ... max period: 00007fffffffffff [ 0.060016] ... fixed-purpose events: 3 [ 0.061011] ... event mask: 000000070000000f [ 0.063349] rcu: Hierarchical SRCU implementation. [ 0.065666] smp: Bringing up secondary CPUs ... [ 0.066587] x86: Booting SMP configuration: [ 0.067028] .... node #0, CPUs: #1 #2 #3 [ 0.076115] smp: Brought up 1 node, 4 CPUs [ 0.078022] smpboot: Max logical packages: 1 [ 0.079021] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.194115] node 0 deferred pages initialised in 109ms [ 0.197499] devtmpfs: initialized [ 0.198282] x86/mm: Memory block size: 128MB [ 0.206491] gcov: version magic: 0x41383552 [ 0.210000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.214099] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.217524] pinctrl core: initialized pinctrl subsystem [ 0.218242] [ 0.219008] ************************************************************* [ 0.221021] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.224013] ** ** [ 0.227023] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.230025] ** ** [ 0.233013] ** This means that this kernel is built to expose internal ** [ 0.235011] ** IOMMU data structures, which may compromise security on ** [ 0.237010] ** your system. ** [ 0.240029] ** ** [ 0.242019] ** If you see this message and you are not debugging the ** [ 0.245014] ** kernel, report this immediately to your vendor! ** [ 0.246020] ** ** [ 0.248010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.250017] ************************************************************* [ 0.254247] NET: Registered protocol family 16 [ 0.257169] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.258000] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.258000] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.264015] cpuidle: using governor menu [ 0.266000] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.276626] PCI: Using configuration type 1 for base access [ 0.283011] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.293071] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.298024] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.303101] cryptd: max_cpu_qlen set to 1000 [ 0.307010] ACPI: Added _OSI(Module Device) [ 0.309048] ACPI: Added _OSI(Processor Device) [ 0.310065] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.312013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.318962] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.324595] ACPI: Interpreter enabled [ 0.325068] ACPI: PM: (supports S0 S3 S4 S5) [ 0.329018] ACPI: Using IOAPIC for interrupt routing [ 0.332330] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.336158] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.343427] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.345033] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.347017] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.350072] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.354247] acpiphp: Slot [2] registered [ 0.356094] acpiphp: Slot [3] registered [ 0.357078] acpiphp: Slot [4] registered [ 0.358077] acpiphp: Slot [5] registered [ 0.360095] acpiphp: Slot [6] registered [ 0.361113] acpiphp: Slot [7] registered [ 0.362080] acpiphp: Slot [8] registered [ 0.363095] acpiphp: Slot [9] registered [ 0.365075] acpiphp: Slot [10] registered [ 0.369123] acpiphp: Slot [11] registered [ 0.370077] acpiphp: Slot [12] registered [ 0.371074] acpiphp: Slot [13] registered [ 0.375182] acpiphp: Slot [14] registered [ 0.376096] acpiphp: Slot [15] registered [ 0.381134] acpiphp: Slot [16] registered [ 0.382077] acpiphp: Slot [17] registered [ 0.383074] acpiphp: Slot [18] registered [ 0.388017] acpiphp: Slot [19] registered [ 0.389080] acpiphp: Slot [20] registered [ 0.390084] acpiphp: Slot [21] registered [ 0.391087] acpiphp: Slot [22] registered [ 0.392081] acpiphp: Slot [23] registered [ 0.394099] acpiphp: Slot [24] registered [ 0.396096] acpiphp: Slot [25] registered [ 0.398115] acpiphp: Slot [26] registered [ 0.399087] acpiphp: Slot [27] registered [ 0.400096] acpiphp: Slot [28] registered [ 0.402153] acpiphp: Slot [29] registered [ 0.403128] acpiphp: Slot [30] registered [ 0.405103] acpiphp: Slot [31] registered [ 0.406000] PCI host bridge to bus 0000:00 [ 0.406000] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.408022] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.410018] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.412026] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.415023] pci_bus 0000:00: root bus resource [mem 0x180000000-0x1ffffffff window] [ 0.418026] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.421232] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.425526] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.432000] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.436029] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.441051] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.445022] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.447018] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.450051] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.452472] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.455957] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.459039] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.462631] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.466011] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.472015] pci 0000:00:02.0: reg 0x20: [mem 0xfebf4000-0xfebf7fff 64bit pref] [ 0.477013] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.482000] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.491028] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.509018] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.521013] pci 0000:00:05.0: reg 0x20: [mem 0xfebf8000-0xfebfbfff 64bit pref] [ 0.530000] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.534000] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.536017] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.542000] pci 0000:00:06.0: reg 0x20: [mem 0xfebfc000-0xfebfffff 64bit pref] [ 0.550000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.552371] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.554366] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.556463] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.558246] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.561860] iommu: Default domain type: Passthrough [ 0.562733] SCSI subsystem initialized [ 0.563000] ACPI: bus type USB registered [ 0.563000] usbcore: registered new interface driver usbfs [ 0.563000] usbcore: registered new interface driver hub [ 0.563000] usbcore: registered new device driver usb [ 0.563000] pps_core: LinuxPPS API ver. 1 registered [ 0.563000] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.563000] PTP clock support registered [ 0.563755] EDAC MC: Ver: 3.0.0 [ 0.566152] PCI: Using ACPI for IRQ routing [ 0.568894] NetLabel: Initializing [ 0.570010] NetLabel: domain hash size = 128 [ 0.572018] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.575117] NetLabel: unlabeled traffic allowed by default [ 0.578452] vgaarb: loaded [ 0.579725] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.580008] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.582457] clocksource: Switched to clocksource kvm-clock [ 0.712699] VFS: Disk quotas dquot_6.6.0 [ 0.714109] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.716058] *** VALIDATE ramfs *** [ 0.717297] *** VALIDATE hugetlbfs *** [ 0.721914] pnp: PnP ACPI init [ 0.724805] pnp: PnP ACPI: found 6 devices [ 0.744673] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.747149] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.748687] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.750787] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.752887] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.755010] pci_bus 0000:00: resource 8 [mem 0x180000000-0x1ffffffff window] [ 0.757572] NET: Registered protocol family 2 [ 0.761852] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.770368] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.779841] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.786443] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.790753] TCP: Hash tables configured (established 65536 bind 65536) [ 0.793727] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.797349] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.800177] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.803135] NET: Registered protocol family 1 [ 0.805795] RPC: Registered named UNIX socket transport module. [ 0.807935] RPC: Registered udp transport module. [ 0.809372] RPC: Registered tcp transport module. [ 0.810756] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.812859] NET: Registered protocol family 44 [ 0.814168] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.816335] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.818645] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.821075] PCI: CLS 0 bytes, default 64 [ 0.822809] Unpacking initramfs... [ 3.939535] debug: unmapping init [mem 0xffff8daf7cc64000-0xffff8daf7ffcffff] [ 3.958195] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 3.964926] software IO TLB: mapped [mem 0x00000000b8c64000-0x00000000bcc64000] (64MB) [ 3.976332] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 5.349704] Initialise system trusted keyrings [ 5.351394] Key type blacklist registered [ 5.352961] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 5.363441] zbud: loaded [ 5.367305] *** VALIDATE nfs *** [ 5.368339] *** VALIDATE nfs4 *** [ 5.370027] pstore: using deflate compression [ 5.382025] Platform Keyring initialized [ 5.618484] NET: Registered protocol family 38 [ 5.621411] Key type asymmetric registered [ 5.624751] Asymmetric key parser 'x509' registered [ 5.630500] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 5.639244] io scheduler mq-deadline registered [ 5.641018] io scheduler kyber registered [ 5.642872] io scheduler bfq registered [ 5.645301] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 5.657566] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 5.666940] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 5.669486] ACPI: Power Button [PWRF] [ 6.114720] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 6.494595] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 6.909022] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 7.093641] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 7.181413] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 7.198468] Non-volatile memory driver v1.3 [ 7.203192] Linux agpgart interface v0.103 [ 7.394493] virtio_blk virtio1: [vda] 67992 512-byte logical blocks (34.8 MB/33.2 MiB) [ 7.404167] vda: detected capacity change from 0 to 34811904 [ 7.475835] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 7.491793] vdb: detected capacity change from 0 to 1073741824 [ 7.550150] libphy: Fixed MDIO Bus: probed [ 7.638229] usbcore: registered new interface driver usbserial_generic [ 7.640273] usbserial: USB Serial support registered for generic [ 7.646346] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 7.871376] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 7.895910] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 7.898754] mousedev: PS/2 mouse device common for all mice [ 7.901958] rtc_cmos 00:05: RTC can wake from S4 [ 7.904842] rtc_cmos 00:05: registered as rtc0 [ 7.906261] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 7.908704] intel_pstate: CPU model not supported [ 7.923579] hid: raw HID events driver (C) Jiri Kosina [ 7.935980] usbcore: registered new interface driver usbhid [ 7.938275] usbhid: USB HID core driver [ 7.945806] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 7.956455] drop_monitor: Initializing network drop monitor service [ 7.956570] Initializing XFRM netlink socket [ 7.956922] NET: Registered protocol family 10 [ 7.962049] Segment Routing with IPv6 [ 7.981143] NET: Registered protocol family 17 [ 7.982856] mpls_gso: MPLS GSO support [ 7.992691] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 8.028753] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 8.284775] RAS: Correctable Errors collector initialized. [ 8.291837] AVX version of gcm_enc/dec engaged. [ 8.293377] AES CTR mode by8 optimization enabled [ 8.548873] sched_clock: Marking stable (8548854844, 0)->(9722565052, -1173710208) [ 8.568887] registered taskstats version 1 [ 8.576292] Loading compiled-in X.509 certificates [ 8.578698] zswap: loaded using pool lzo/zbud [ 8.654498] Key type big_key registered [ 8.667598] Key type encrypted registered [ 8.669258] ima: No TPM chip found, activating TPM-bypass! [ 8.671244] ima: Allocated hash algorithm: sha1 [ 8.673040] ima: No architecture policies found [ 8.674652] evm: Initialising EVM extended attributes: [ 8.676216] evm: security.selinux [ 8.677545] evm: security.ima [ 8.683829] evm: security.capability [ 8.691034] evm: HMAC attrs: 0x1 [ 8.695151] rtc_cmos 00:05: setting system clock to 2025-10-24 16:02:53 UTC (1761321773) [ 8.704699] debug: unmapping init [mem 0xffffffffbc603000-0xffffffffbc7fffff] [ 8.708175] debug: unmapping init [mem 0xffffffffbb382000-0xffffffffbb658fff] [ 8.730693] Write protecting the kernel read-only data: 28672k [ 8.744409] debug: unmapping init [mem 0xffffffffb9a03000-0xffffffffb9bfffff] [ 8.776152] debug: unmapping init [mem 0xffffffffba314000-0xffffffffba3fffff] [ 8.901755] 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) [ 8.909789] systemd[1]: Detected virtualization kvm. [ 8.911536] systemd[1]: Detected architecture x86-64. [ 8.913083] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 8.963679] systemd[1]: No hostname configured. [ 8.965607] systemd[1]: Set hostname to . [ 8.974673] random: systemd: uninitialized urandom read (16 bytes read) [ 8.982705] systemd[1]: Initializing machine ID from random generator. [ 9.418275] random: systemd: uninitialized urandom read (16 bytes read) [ 9.420837] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 9.456553] random: systemd: uninitialized urandom read (16 bytes read) [ 9.458963] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 9.483174] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Setup Virtual Console... [ OK ] Listening on Journal Socket (/dev/log). Starting Apply Kernel Variables... [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. Starting Journal Service... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Timers. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Initrd Root Device. [ OK ] Started Setup Virtual Console. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 11.650680] device-mapper: uevent: version 1.0.3 [ 11.674900] 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. [ 13.524753] virtio_net virtio0 ens2: renamed from eth0 [ 14.310653] scsi host0: ata_piix [ 14.469198] scsi host1: ata_piix [ 14.478970] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 14.490238] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 19.223429] random: crng init done [ 19.224625] random: 7 urandom warning(s) missed due to ratelimiting [ 21.271296] dracut-initqueue[592]: RTNETLINK answers: File exists 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. [ 22.751503] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ 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 Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 26.569988] printk: systemd: 26 output lines suppressed due to ratelimiting [ 27.564964] SELinux: Disabled at runtime. [ 27.682513] 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) [ 27.714154] systemd[1]: Detected virtualization kvm. [ 27.720264] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 29.243227] systemd[1]: initrd-switch-root.service: Succeeded. [ 29.246623] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 29.259929] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 29.267610] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 29.285908] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 29.323988] systemd[1]: Starting Journal Service... Starting Journal Service... [ 29.339980] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-getty.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-serial\x2dgetty.slice. Mounting POSIX Message Queue File System... Mounting Kernel Debug File System... [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on initctl Compatibility Named Pipe. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Reached target Slices. Starting Apply Kernel Variables... [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... Mounting Huge Pages File System... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Activating swap /dev/disk/by-label/SWAP... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Starting Create list of required st…ce nodes for the current kernel... [ 30.033383] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Huge Pages File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started udev Coldplug all Devices. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 30.580307] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 31.518262] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 31.562742] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 32.956213] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 33.256159] EDAC sbridge: Ver: 1.1.2 [ 34.181452] hrtimer: interrupt took 2556967 ns [ 35.482712] Key type dns_resolver registered [ 36.243212] NFS: Registering the id_resolver key type [ 36.245122] Key type id_resolver registered [ 36.246269] Key type id_legacy registered [* ] A start job is running for Configur…-only root support (7s / no limit) [** ] A start job is running for Configur…-only root support (7s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Load/Save Random Seed... Starting Create Volatile Files and Directories... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ 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. [ OK ] Started D-Bus System Message Bus. [ OK ] Started irqbalance daemon. Starting Login Service... Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Started Login Service. Starting Hostname Service... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting System Logging Service... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. [ OK ] Started Authorization Manager. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg236-client login: [ 68.061528] libcfs: loading out-of-tree module taints kernel. [ 68.136638] alg: No test for adler32 (adler32-zlib) [ 68.892482] Key type ._llcrypt registered [ 68.894102] Key type .llcrypt registered [ 69.092352] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 69.442323] Lustre: Lustre: Build Version: 2.15.7_12_gd220bd5 [ 69.826949] LNet: Added LNI 192.168.202.36@tcp [8/256/0/180] [ 69.828983] LNet: Accept secure, port 988 [ 71.472138] Key type lgssc registered [ 72.212302] Lustre: Echo OBD driver; http://www.lustre.org/ [ 147.140964] Lustre: Mounted lustre-client [ 149.763327] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 159.543789] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing check_logdir /tmp/testlogs/ [ 161.571902] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing yml_node [ 163.780315] Lustre: DEBUG MARKER: Client: 2.15.7.12 [ 164.971804] Lustre: DEBUG MARKER: MDS: 2.15.7.12 [ 166.322235] Lustre: DEBUG MARKER: OSS: 2.15.7.12 [ 167.329486] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Fri Oct 24 12:05:31 EDT 2025 [ 172.037593] Lustre: DEBUG MARKER: excepting tests: 59 [ 173.024585] Lustre: lustre-OST0000-osc-ffff8dafc8ece800: disconnect after 24s idle [ 175.665974] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing check_config_client /mnt/lustre [ 186.380584] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 192.233654] Lustre: DEBUG MARKER: == replay-single test 0a: empty replay =================== 12:05:56 (1761321956) [ 196.397444] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 198.627586] Lustre: lustre-MDT0000-mdc-ffff8dafc8ece800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 205.792433] Lustre: 2271:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761321963/real 1761321963] req@000000000fb65a0e x1846879803415360/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761321970 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 205.806617] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 217.056249] Lustre: lustre-OST0000-osc-ffff8dafc8ece800: disconnect after 24s idle [ 217.058414] Lustre: Skipped 1 previous similar message [ 223.207493] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b57e7a to 0x3e67870b72b580c6 [ 223.215268] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 229.573875] Lustre: lustre-MDT0000-mdc-ffff8dafc8ece800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 232.278418] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 233.120692] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 237.571605] Lustre: DEBUG MARKER: == replay-single test 0b: ensure object created after recover exists. (3284) ========================================================== 12:06:41 (1761322001) [ 239.589701] Lustre: lustre-OST0000-osc-ffff8dafc8ece800: Connection to lustre-OST0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 254.944346] Lustre: lustre-OST0001-osc-ffff8dafc8ece800: disconnect after 20s idle [ 254.948411] Lustre: Skipped 1 previous similar message [ 254.963818] Lustre: lustre-OST0000-osc-ffff8dafc8ece800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 261.401712] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 262.291227] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 267.545684] Lustre: DEBUG MARKER: == replay-single test 0c: check replay-barrier =========== 12:07:11 (1761322031) [ 271.642892] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 271.725641] Lustre: Unmounted lustre-client [ 302.580459] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc7e05800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 307.697595] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc7e05800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 312.833967] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc7e05800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 317.938581] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc7e05800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 323.054743] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc7e05800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 333.302253] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc7e05800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 333.306831] LustreError: Skipped 1 previous similar message [ 353.776470] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc7e05800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 353.781292] LustreError: Skipped 3 previous similar messages [ 369.142934] Lustre: Mounted lustre-client [ 374.096134] Lustre: DEBUG MARKER: == replay-single test 0d: expired recovery with no clients ========================================================== 12:08:58 (1761322138) [ 377.928573] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 377.995239] Lustre: Unmounted lustre-client [ 408.961700] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 408.967181] LustreError: Skipped 2 previous similar messages [ 475.654803] Lustre: Mounted lustre-client [ 479.988249] Lustre: DEBUG MARKER: == replay-single test 1: simple create =================== 12:10:44 (1761322244) [ 483.021756] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 485.859220] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 493.024166] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322250/real 1761322250] req@0000000079e39e78 x1846879803443904/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322257 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:0.0' [ 493.035074] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 506.037145] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection restored to (at 192.168.202.136@tcp) [ 508.302483] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 508.932822] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 510.178112] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b590cc to 0x3e67870b72b59771 [ 510.182644] Lustre: MGC192.168.202.136@tcp: Connection restored to (at 192.168.202.136@tcp) [ 512.658122] Lustre: DEBUG MARKER: == replay-single test 2a: touch ========================== 12:11:16 (1761322276) [ 515.432922] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 520.674062] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 527.840121] Lustre: 2271:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322285/real 1761322285] req@0000000017ae9a44 x1846879803449280/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322292 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:0.0' [ 527.849388] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 533.986538] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b59771 to 0x3e67870b72b59874 [ 533.992424] Lustre: MGC192.168.202.136@tcp: Connection restored to (at 192.168.202.136@tcp) [ 545.964645] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@000000000bfbb988 x1846879803448704/t21474836484(21474836484) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761322317 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'touch.0' [ 548.074890] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 548.681150] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 552.433575] Lustre: DEBUG MARKER: == replay-single test 2b: touch ========================== 12:11:56 (1761322316) [ 555.256026] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 557.538322] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 564.704330] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322322/real 1761322322] req@00000000075462f0 x1846879803455168/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322329 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 564.714113] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 582.112794] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b59874 to 0x3e67870b72b59ebe [ 582.118358] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 582.122036] Lustre: Skipped 1 previous similar message [ 585.899367] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000b1746675 x1846879803454720/t25769803781(25769803781) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761322357 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'touch.0' [ 588.133514] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 588.786099] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 592.380713] Lustre: DEBUG MARKER: == replay-single test 2c: setstripe replay =============== 12:12:36 (1761322356) [ 595.039158] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 596.449778] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 603.616237] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322361/real 1761322361] req@00000000fc8e7a94 x1846879803460992/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322368 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 603.625284] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 619.690760] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@000000009609ba98 x1846879803460416/t30064771076(30064771076) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 536/600 e 0 to 0 dl 1761322392 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'lfs.0' [ 619.711646] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 619.714827] Lustre: Skipped 1 previous similar message [ 620.770075] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b59ebe to 0x3e67870b72b5a6dd [ 621.754585] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 622.340114] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 625.859757] Lustre: DEBUG MARKER: == replay-single test 2d: setdirstripe replay ============ 12:13:10 (1761322390) [ 628.511566] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 631.266641] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 638.432145] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322396/real 1761322396] req@00000000fea6b276 x1846879803466048/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322403 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 638.441939] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 644.578085] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b5a6dd to 0x3e67870b72b5a80a [ 656.064141] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 656.690747] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 660.361462] Lustre: DEBUG MARKER: == replay-single test 2e: O_CREAT|O_EXCL create replay === 12:13:44 (1761322424) [ 664.302883] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 665.058066] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 668.128148] Lustre: 22557:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322425/real 1761322425] req@000000005237aa38 x1846879803470272/t0(0) o35->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:23/10 lens 392/624 e 0 to 1 dl 1761322432 ref 2 fl Rpc:XQr/0/ffffffff rc 0/-1 job:'openfile.0' [ 676.320182] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 682.466572] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b5a80a to 0x3e67870b72b5ae00 [ 687.277320] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 687.282507] Lustre: Skipped 4 previous similar messages [ 689.454376] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 690.145827] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 693.910759] Lustre: DEBUG MARKER: == replay-single test 3a: replay failed open(O_DIRECTORY) ========================================================== 12:14:18 (1761322458) [ 696.611904] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 704.992170] Lustre: 2268:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322462/real 1761322462] req@00000000417d98e4 x1846879803475648/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322469 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:0.0' [ 705.000492] Lustre: 2268:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 722.082232] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b5ae00 to 0x3e67870b72b5b593 [ 722.139063] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 722.760740] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 726.261715] Lustre: DEBUG MARKER: == replay-single test 3b: replay failed open -ENOMEM ===== 12:14:50 (1761322490) [ 728.915915] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 732.641835] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 732.646313] Lustre: Skipped 1 previous similar message [ 739.808215] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 739.812591] LustreError: Skipped 1 previous similar message [ 755.861471] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 756.451095] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 760.092686] Lustre: DEBUG MARKER: == replay-single test 3c: replay failed open -ENOMEM ===== 12:15:24 (1761322524) [ 762.938352] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 776.672158] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322534/real 1761322534] req@000000008ad1fe53 x1846879803486080/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322541 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:1.0' [ 776.683063] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 789.751073] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 790.361572] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 794.191481] Lustre: DEBUG MARKER: == replay-single test 4a: |x| 10 open(O_CREAT)s ========== 12:15:58 (1761322558) [ 797.220651] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 804.320341] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 804.325633] LustreError: Skipped 1 previous similar message [ 821.417515] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000c0438b0e x1846879803490048/t55834574851(55834574851) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761322593 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'bash.0' [ 821.468395] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 821.472419] Lustre: Skipped 6 previous similar messages [ 822.498221] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b5bc54 to 0x3e67870b72b5c61e [ 822.501465] Lustre: Skipped 2 previous similar messages [ 823.535890] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 824.109367] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 827.771459] Lustre: DEBUG MARKER: == replay-single test 4b: |x| rm 10 files ================ 12:16:32 (1761322592) [ 830.577740] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 856.199287] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 856.794795] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 860.343323] Lustre: DEBUG MARKER: == replay-single test 5: |x| 220 open(O_CREAT) =========== 12:17:04 (1761322624) [ 863.194487] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 866.786219] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 866.792275] Lustre: Skipped 3 previous similar messages [ 887.977173] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@0000000084bc5d9f x1846879803513408/t64424509443(64424509443) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761322659 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'bash.0' [ 887.984031] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 9 previous similar messages [ 890.710748] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 891.303867] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 901.455600] Lustre: DEBUG MARKER: == replay-single test 6a: mkdir + contained create ======= 12:17:45 (1761322665) [ 904.133251] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 913.376153] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322671/real 1761322671] req@0000000055150a17 x1846879803744064/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322678 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:1.0' [ 913.387445] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 928.964037] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 929.547093] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 935.073195] Lustre: DEBUG MARKER: == replay-single test 6b: |X| rmdir ====================== 12:18:19 (1761322699) [ 937.794440] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 948.704221] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 948.708856] LustreError: Skipped 3 previous similar messages [ 954.850334] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b65e18 to 0x3e67870b72b65f22 [ 954.854271] Lustre: Skipped 3 previous similar messages [ 962.632339] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 963.203259] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 966.729432] Lustre: DEBUG MARKER: == replay-single test 7: mkdir |X| contained create ====== 12:18:51 (1761322731) [ 969.442515] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1002.459832] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1002.996572] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1006.469284] Lustre: DEBUG MARKER: == replay-single test 8: creat open |X| close ============ 12:19:30 (1761322770) [ 1009.137819] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1039.546052] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000079463f4 x1846879803760064/t81604378634(81604378634) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 664/600 e 0 to 0 dl 1761322811 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'multiop.0' [ 1039.554925] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 219 previous similar messages [ 1042.374664] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1043.399827] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1049.568607] Lustre: DEBUG MARKER: == replay-single test 9: |X| create (same inum/gen) ====== 12:20:13 (1761322813) [ 1054.837716] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1084.907647] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 1084.920389] Lustre: Skipped 13 previous similar messages [ 1098.447040] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1099.791905] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1106.064645] Lustre: DEBUG MARKER: == replay-single test 10: create |X| rename unlink ======= 12:21:09 (1761322869) [ 1110.816672] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1147.395430] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1148.206700] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1153.274840] Lustre: DEBUG MARKER: == replay-single test 11: create open write rename |X| create-old-name read ========================================================== 12:21:57 (1761322917) [ 1157.679517] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1160.676797] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1160.685871] Lustre: Skipped 6 previous similar messages [ 1188.534693] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000259a2227 x1846879803780096/t94489280521(94489280521) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761322960 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'bash.0' [ 1190.923524] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1191.611699] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1196.012849] Lustre: DEBUG MARKER: == replay-single test 12: open, unlink |X| close ========= 12:22:40 (1761322960) [ 1199.493315] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1211.872168] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761322969/real 1761322969] req@00000000b10f2a62 x1846879803787840/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761322976 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 1211.886516] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 6 previous similar messages [ 1211.890155] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 1211.897707] LustreError: Skipped 5 previous similar messages [ 1218.022111] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b67b4c to 0x3e67870b72b680cb [ 1218.027314] Lustre: Skipped 5 previous similar messages [ 1222.312645] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status -116, old was 0 req@00000000c8526d79 x1846879803787520/t98784247819(98784247819) o35->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:23/10 lens 392/456 e 0 to 0 dl 1761322995 ref 2 fl Interpret:RQU/4/0 rc -116/-116 job:'multiop.0' [ 1222.322802] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 2 previous similar messages [ 1224.582047] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1225.238804] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1229.744838] Lustre: DEBUG MARKER: == replay-single test 13: open chmod 0 |x| write close === 12:23:13 (1761322993) [ 1234.965350] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1270.361690] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1271.449843] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1276.196740] Lustre: DEBUG MARKER: == replay-single test 14: open(O_CREAT), unlink |X| close ========================================================== 12:24:00 (1761323040) [ 1280.814126] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1307.159624] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000e25d7575 x1846879803780416/t94489280523(94489280523) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 576/600 e 0 to 0 dl 1761323078 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'grep.0' [ 1307.170466] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 2 previous similar messages [ 1315.951100] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1317.174955] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1322.872829] Lustre: DEBUG MARKER: == replay-single test 15: open(O_CREAT), unlink |X| touch new, close ========================================================== 12:24:46 (1761323086) [ 1327.377299] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1366.441647] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1367.455755] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1373.144495] Lustre: DEBUG MARKER: == replay-single test 16: |X| open(O_CREAT), unlink, touch new, unlink new ========================================================== 12:25:37 (1761323137) [ 1378.620381] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1416.713766] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1417.958194] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1423.902920] Lustre: DEBUG MARKER: == replay-single test 17: |X| open(O_CREAT), |replay| close ========================================================== 12:26:27 (1761323187) [ 1428.697095] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1458.618197] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000e25d7575 x1846879803780416/t94489280523(94489280523) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 576/600 e 0 to 0 dl 1761323230 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'grep.0' [ 1458.638840] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 5 previous similar messages [ 1468.372032] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1469.612574] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1475.418954] Lustre: DEBUG MARKER: == replay-single test 18: open(O_CREAT), unlink, touch new, close, touch, unlink ========================================================== 12:27:19 (1761323239) [ 1480.285972] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1516.621802] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1517.686643] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1523.664799] Lustre: DEBUG MARKER: == replay-single test 19: mcreate, open, write, rename === 12:28:07 (1761323287) [ 1528.971281] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1565.223908] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1566.104985] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1570.143527] Lustre: DEBUG MARKER: == replay-single test 20a: |X| open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 12:28:54 (1761323334) [ 1573.364692] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1606.855636] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 1606.859864] Lustre: Skipped 22 previous similar messages [ 1610.018958] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1611.089840] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1616.768711] Lustre: DEBUG MARKER: == replay-single test 20b: write, unlink, eviction, replay (test mds_cleanup_orphans) ========================================================== 12:29:40 (1761323380) [ 1620.485787] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation ldlm_enqueue to node 192.168.202.136@tcp failed: rc = -107 [ 1620.490462] LustreError: Skipped 12 previous similar messages [ 1620.495421] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1620.500878] LustreError: 58444:0:(file.c:5205:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000007:0x1:0x0] error: rc = -5 [ 1620.501702] LustreError: 58459:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff8dafc80d5800: inode [0x200001b71:0x118:0x0] mdc close failed: rc = -108 [ 1620.501796] LustreError: 58400:0:(vvp_io.c:1864:vvp_io_init()) lustre: refresh file layout [0x200001b71:0x132:0x0] error -108. [ 1620.512569] LustreError: 58459:0:(file.c:246:ll_close_inode_openhandle()) Skipped 1 previous similar message [ 1648.766707] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1649.477738] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1656.930431] Lustre: DEBUG MARKER: before 2844, after 2844 [ 1659.768334] Lustre: DEBUG MARKER: == replay-single test 20c: check that client eviction does not affect file content ========================================================== 12:30:23 (1761323423) [ 1661.630343] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation ldlm_enqueue to node 192.168.202.136@tcp failed: rc = -107 [ 1661.638162] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1661.644140] LustreError: 60408:0:(file.c:5205:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000007:0x1:0x0] error: rc = -5 [ 1666.574075] Lustre: DEBUG MARKER: == replay-single test 21: |X| open(O_CREAT), unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 12:30:30 (1761323430) [ 1670.046597] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1672.678646] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1672.685778] Lustre: Skipped 12 previous similar messages [ 1703.263380] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1704.018927] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1708.424437] Lustre: DEBUG MARKER: == replay-single test 22: open(O_CREAT), |X| unlink, replay, close (test mds_cleanup_orphans) ========================================================== 12:31:12 (1761323472) [ 1711.904728] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1730.023797] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b6b743 to 0x3e67870b72b6bbaa [ 1730.029579] Lustre: Skipped 10 previous similar messages [ 1742.342799] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000bb88f85b x1846879803862784/t146028888070(146028888070) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761323514 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'multiop.0' [ 1742.352578] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 10 previous similar messages [ 1748.616564] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1749.642911] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1755.568111] Lustre: DEBUG MARKER: == replay-single test 23: open(O_CREAT), |X| unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 12:31:59 (1761323519) [ 1760.477836] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1769.952790] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761323527/real 1761323527] req@000000003b4711b1 x1846879803871232/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761323534 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:4.0' [ 1770.013907] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1770.023374] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 1770.028387] LustreError: Skipped 11 previous similar messages [ 1798.156856] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1798.825696] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1803.215164] Lustre: DEBUG MARKER: == replay-single test 24: open(O_CREAT), replay, unlink, close (test mds_cleanup_orphans) ========================================================== 12:32:47 (1761323567) [ 1807.438783] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1843.293618] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1844.035416] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1848.256716] Lustre: DEBUG MARKER: == replay-single test 25: open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 12:33:32 (1761323612) [ 1851.708106] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1876.364856] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1877.043465] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1880.800805] Lustre: DEBUG MARKER: == replay-single test 26: |X| open(O_CREAT), unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 12:34:05 (1761323645) [ 1883.723469] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1910.150483] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1910.799537] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1914.583797] Lustre: DEBUG MARKER: == replay-single test 27: |X| open(O_CREAT), unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 12:34:38 (1761323678) [ 1917.347997] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1943.811788] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1944.439140] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1948.345258] Lustre: DEBUG MARKER: == replay-single test 28: open(O_CREAT), |X| unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 12:35:12 (1761323712) [ 1951.519743] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1977.766810] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1978.438206] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1982.391513] Lustre: DEBUG MARKER: == replay-single test 29: open(O_CREAT), |X| unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 12:35:46 (1761323746) [ 1985.463880] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2010.861896] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2011.484937] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2015.306630] Lustre: DEBUG MARKER: == replay-single test 30: open(O_CREAT) two, unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 12:36:19 (1761323779) [ 2018.344270] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2044.670529] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2045.295827] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2049.008352] Lustre: DEBUG MARKER: == replay-single test 31: open(O_CREAT) two, unlink one, |X| unlink one, close two (test mds_cleanup_orphans) ========================================================== 12:36:53 (1761323813) [ 2051.814355] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2078.440666] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2079.093956] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2082.978347] Lustre: DEBUG MARKER: == replay-single test 32: close() notices client eviction; close() after client eviction ========================================================== 12:37:27 (1761323847) [ 2084.730310] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation ldlm_enqueue to node 192.168.202.136@tcp failed: rc = -107 [ 2084.738371] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2084.743703] LustreError: 78064:0:(file.c:5205:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000007:0x1:0x0] error: rc = -5 [ 2088.439352] Lustre: DEBUG MARKER: == replay-single test 33a: fid seq shouldn't be reused after abort recovery ========================================================== 12:37:32 (1761323852) [ 2090.824313] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2098.148635] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2109.480225] Lustre: DEBUG MARKER: == replay-single test 33b: test fid seq allocation ======= 12:37:53 (1761323873) [ 2112.364141] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2118.627906] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2132.072110] Lustre: DEBUG MARKER: == replay-single test 34: abort recovery before client does replay (test mds_cleanup_orphans) ========================================================== 12:38:16 (1761323896) [ 2135.003876] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2144.228042] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2144.233276] LustreError: 81347:0:(file.c:5205:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000007:0x1:0x0] error: rc = -5 [ 2154.139214] Lustre: DEBUG MARKER: == replay-single test 35: test recovery from llog for unlink op ========================================================== 12:38:38 (1761323918) [ 2164.711549] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2164.717576] LustreError: 82387:0:(file.c:5205:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000007:0x1:0x0] error: rc = -5 [ 2174.721668] Lustre: DEBUG MARKER: == replay-single test 36: don't resend cancel ============ 12:38:59 (1761323939) [ 2177.599036] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2202.558971] Lustre: DEBUG MARKER: == replay-single test 37: abort recovery before client does replay (test mds_cleanup_orphans for directories) ========================================================== 12:39:26 (1761323966) [ 2205.480339] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2214.373857] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2214.373947] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 2214.382736] Lustre: Skipped 38 previous similar messages [ 2225.862187] Lustre: DEBUG MARKER: == replay-single test 38: test recovery from unlink llog (test llog_gen_rec) ========================================================== 12:39:50 (1761323990) [ 2235.706673] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2262.763228] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2263.361136] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2271.398430] Lustre: DEBUG MARKER: == replay-single test 39: test recovery from unlink llog (test llog_gen_rec) ========================================================== 12:40:35 (1761324035) [ 2278.420236] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2284.513848] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2284.519287] Lustre: Skipped 18 previous similar messages [ 2308.319703] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2308.926300] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2317.779291] Lustre: DEBUG MARKER: == replay-single test 40: cause recovery in ptlrpc, ensure IO continues ========================================================== 12:41:22 (1761324082) [ 2318.331444] Lustre: DEBUG MARKER: SKIP: replay-single test_40 layout_lock needs MDS connection for IO [ 2318.954032] Lustre: DEBUG MARKER: == replay-single test 41: read from a valid osc while other oscs are invalid ========================================================== 12:41:23 (1761324083) [ 2322.235650] Lustre: DEBUG MARKER: == replay-single test 42: recovery after ost failure ===== 12:41:26 (1761324086) [ 2328.998032] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 2394.889262] Lustre: DEBUG MARKER: == replay-single test 43: mds osc import failure during recovery; don't LBUG ========================================================== 12:42:39 (1761324159) [ 2397.885460] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2406.368143] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761324164/real 1761324164] req@0000000024fc18c0 x1846879804957952/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761324171 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:0.0' [ 2406.377676] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 2406.380924] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 2406.385190] LustreError: Skipped 16 previous similar messages [ 2423.458524] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72b8bfb9 to 0x3e67870b72ba32e3 [ 2423.462747] Lustre: Skipped 17 previous similar messages [ 2424.485542] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2425.091768] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2438.776016] Lustre: DEBUG MARKER: == replay-single test 44a: race in target handle connect ========================================================== 12:43:23 (1761324203) [ 2501.600942] Lustre: DEBUG MARKER: == replay-single test 44b: race in target handle connect ========================================================== 12:44:25 (1761324265) [ 2508.773760] LustreError: 94518:0:(lmv_obd.c:1273:lmv_statfs()) lustre-MDT0000-mdc-ffff8dafc80d5800: can't stat MDS #0: rc = -114 [ 2509.405989] LustreError: 94537:0:(lmv_obd.c:1273:lmv_statfs()) lustre-MDT0000-mdc-ffff8dafc80d5800: can't stat MDS #0: rc = -114 [ 2510.663268] LustreError: 94575:0:(lmv_obd.c:1273:lmv_statfs()) lustre-MDT0000-mdc-ffff8dafc80d5800: can't stat MDS #0: rc = -114 [ 2510.667013] LustreError: 94575:0:(lmv_obd.c:1273:lmv_statfs()) Skipped 1 previous similar message [ 2513.226665] LustreError: 94651:0:(lmv_obd.c:1273:lmv_statfs()) lustre-MDT0000-mdc-ffff8dafc80d5800: can't stat MDS #0: rc = -114 [ 2513.230396] LustreError: 94651:0:(lmv_obd.c:1273:lmv_statfs()) Skipped 3 previous similar messages [ 2516.615309] Lustre: DEBUG MARKER: == replay-single test 44c: race in target handle connect ========================================================== 12:44:40 (1761324280) [ 2520.823810] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2528.740092] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2562.571247] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2563.141467] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2566.683458] Lustre: DEBUG MARKER: == replay-single test 45: Handle failed close ============ 12:45:30 (1761324330) [ 2566.763116] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [ 2566.769452] LustreError: 97271:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff8dafc80d5800: inode [0x20001b1b1:0x1:0x0] mdc close failed: rc = -108 [ 2566.782296] LustreError: lustre-MDT0000-mdc-ffff8dafc80d5800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2569.898209] Lustre: DEBUG MARKER: == replay-single test 46: Don't leak file handle after open resend (3325) ========================================================== 12:45:34 (1761324334) [ 2601.525924] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2602.074895] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2605.728096] Lustre: DEBUG MARKER: == replay-single test 47: MDS->OSC failure during precreate cleanup (2824) ========================================================== 12:46:10 (1761324370) [ 2625.068162] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2625.655428] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 2691.091397] Lustre: DEBUG MARKER: == replay-single test 48: MDS->OSC failure during precreate cleanup (2824) ========================================================== 12:47:35 (1761324455) [ 2693.842648] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2715.304969] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@000000007400cae9 x1846879805018112/t240518168679(240518168679) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761324502 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'createmany.0' [ 2715.311236] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 18 previous similar messages [ 2777.641321] Lustre: DEBUG MARKER: == replay-single test 50: Double OSC recovery, don't LASSERT (3812) ========================================================== 12:49:02 (1761324542) [ 2785.455390] Lustre: DEBUG MARKER: == replay-single test 52: time out lock replay (3764) ==== 12:49:09 (1761324549) [ 2827.242955] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 2827.245417] Lustre: Skipped 29 previous similar messages [ 2829.394761] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2829.959235] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2833.776158] Lustre: DEBUG MARKER: == replay-single test 53a: |X| close request while two MDC requests in flight ========================================================== 12:49:58 (1761324598) [ 2838.064619] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2861.590903] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2862.142803] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2865.725983] Lustre: DEBUG MARKER: == replay-single test 53b: |X| open request while two MDC requests in flight ========================================================== 12:50:30 (1761324630) [ 2870.073457] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2895.369487] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2895.933073] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2899.320431] Lustre: DEBUG MARKER: == replay-single test 53c: |X| open request and close request while two MDC requests in flight ========================================================== 12:51:03 (1761324663) [ 2903.301626] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2904.033547] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2904.037374] Lustre: Skipped 24 previous similar messages [ 2930.764469] Lustre: DEBUG MARKER: == replay-single test 53d: close reply while two MDC requests in flight ========================================================== 12:51:35 (1761324695) [ 2956.860749] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2957.434662] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2960.862461] Lustre: DEBUG MARKER: == replay-single test 53e: |X| open reply while two MDC requests in flight ========================================================== 12:52:05 (1761324725) [ 2964.991870] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2990.547686] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2991.057600] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2994.604361] Lustre: DEBUG MARKER: == replay-single test 53f: |X| open reply and close reply while two MDC requests in flight ========================================================== 12:52:38 (1761324758) [ 2998.724490] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3011.552155] Lustre: 2271:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761324769/real 1761324769] req@00000000b6686abc x1846879805084544/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761324776 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 3011.561382] Lustre: 2271:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 18 previous similar messages [ 3011.564281] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 3011.568225] LustreError: Skipped 10 previous similar messages [ 3026.943562] Lustre: DEBUG MARKER: == replay-single test 53g: |X| drop open reply and close request while close and open are both in flight ========================================================== 12:53:11 (1761324791) [ 3031.460206] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3056.609822] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72ba8c7e to 0x3e67870b72ba92f9 [ 3056.614155] Lustre: Skipped 11 previous similar messages [ 3065.488241] Lustre: DEBUG MARKER: == replay-single test 53h: open request and close reply while two MDC requests in flight ========================================================== 12:53:49 (1761324829) [ 3070.631657] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3098.425551] Lustre: DEBUG MARKER: == replay-single test 55: let MDS_CHECK_RESENT return the original return code instead of 0 ========================================================== 12:54:22 (1761324862) [ 3122.511158] Lustre: DEBUG MARKER: == replay-single test 56: don't replay a symlink open request (3440) ========================================================== 12:54:46 (1761324886) [ 3125.119075] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3150.351393] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3150.870213] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3164.466881] Lustre: DEBUG MARKER: == replay-single test 57: test recovery from llog for setattr op ========================================================== 12:55:28 (1761324928) [ 3167.257393] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3200.385961] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3200.873812] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3208.239708] Lustre: DEBUG MARKER: == replay-single test 58a: test recovery from llog for setattr op (test llog_gen_rec) ========================================================== 12:56:12 (1761324972) [ 3217.063888] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3250.532773] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3251.028851] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3265.912629] Lustre: DEBUG MARKER: == replay-single test 58b: test replay of setxattr op ==== 12:57:10 (1761325030) [ 3266.312305] Lustre: Mounted lustre-client [ 3269.763771] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3294.843908] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3295.335487] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3296.962945] Lustre: Unmounted lustre-client [ 3298.723792] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount FULL mgc.*.mgs_server_uuid [ 3299.299650] Lustre: DEBUG MARKER: mgc.*.mgs_server_uuid in FULL state after 0 sec [ 3301.219287] Lustre: DEBUG MARKER: == replay-single test 58c: resend/reconstruct setxattr op ========================================================== 12:57:45 (1761325065) [ 3306.662368] Lustre: Mounted lustre-client [ 3351.337130] Lustre: Unmounted lustre-client [ 3353.374618] Lustre: DEBUG MARKER: SKIP: replay-single test_59 skipping ALWAYS excluded test 59 [ 3353.907110] Lustre: DEBUG MARKER: == replay-single test 60: test llog post recovery init vs llog unlink ========================================================== 12:58:38 (1761325118) [ 3358.146258] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3390.085187] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3390.626352] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3394.349529] Lustre: DEBUG MARKER: == replay-single test 61a: test race llog recovery vs llog cleanup ========================================================== 12:59:18 (1761325158) [ 3399.900311] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 3445.555983] Lustre: lustre-OST0000-osc-ffff8dafc80d5800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 3445.560263] Lustre: Skipped 30 previous similar messages [ 3449.046528] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3449.603912] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 3483.708670] Lustre: DEBUG MARKER: == replay-single test 61b: test race mds llog sync vs llog cleanup ========================================================== 13:00:48 (1761325248) [ 3519.457503] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3519.461181] Lustre: Skipped 17 previous similar messages [ 3537.935384] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3538.491581] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3541.944779] Lustre: DEBUG MARKER: == replay-single test 61c: test race mds llog sync vs llog cleanup ========================================================== 13:01:46 (1761325306) [ 3571.561633] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3572.084870] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 3575.854937] Lustre: DEBUG MARKER: == replay-single test 61d: error in llog_setup should cleanup the llog context correctly ========================================================== 13:02:20 (1761325340) [ 3586.928621] Lustre: DEBUG MARKER: == replay-single test 62: don't mis-drop resent replay === 13:02:31 (1761325351) [ 3590.795774] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3639.264178] Lustre: 2267:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761325383/real 1761325383] req@000000005451b498 x1846879806999296/t317827579906(317827579906) o36->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 528/448 e 0 to 1 dl 1761325404 ref 2 fl Rpc:XQr/4/ffffffff rc 0/-1 job:'mcreate.0' [ 3639.273269] Lustre: 2267:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 18 previous similar messages [ 3639.277164] LustreError: 2267:0:(client.c:3110:ptlrpc_replay_interpret()) @@@ request replay timed out req@000000005451b498 x1846879806999296/t317827579906(317827579906) o36->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 528/448 e 0 to 1 dl 1761325404 ref 2 fl Interpret:EXQU/4/ffffffff rc -110/-1 job:'mcreate.0' [ 3639.305377] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@000000005f910c4b x1846879806999744/t317827579908(317827579908) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 592/600 e 0 to 0 dl 1761325425 ref 2 fl Interpret:RQU/4/0 rc 301/301 job:'createmany.0' [ 3639.315216] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 19 previous similar messages [ 3641.424804] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3641.969343] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3645.891275] Lustre: DEBUG MARKER: == replay-single test 65a: AT: verify early replies ====== 13:03:30 (1761325410) [ 3687.216658] Lustre: DEBUG MARKER: == replay-single test 65b: AT: verify early replies on packed reply / bulk ========================================================== 13:04:11 (1761325451) [ 3719.501248] Lustre: DEBUG MARKER: == replay-single test 66a: AT: verify MDT service time adjusts with no early replies ========================================================== 13:04:43 (1761325483) [ 3770.187705] Lustre: DEBUG MARKER: == replay-single test 66b: AT: verify net latency adjusts ========================================================== 13:05:34 (1761325534) [ 3792.443375] LustreError: 134949:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c sleeping for 6000ms [ 3798.480117] LustreError: 134949:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c awake [ 3798.484503] LustreError: 134949:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c sleeping for 6000ms [ 3804.520107] LustreError: 134949:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c awake [ 3804.524918] LustreError: 2269:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c sleeping for 6000ms [ 3810.616075] LustreError: 2269:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c awake [ 3810.621747] LustreError: 134949:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c sleeping for 6000ms [ 3816.656092] LustreError: 134949:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 50c awake [ 3818.878682] Lustre: DEBUG MARKER: == replay-single test 67a: AT: verify slow request processing doesn't induce reconnects ========================================================== 13:06:23 (1761325583) [ 3869.547597] Lustre: DEBUG MARKER: == replay-single test 67b: AT: verify instant slowdown doesn't induce reconnects ========================================================== 13:07:13 (1761325633) [ 3894.235108] Lustre: DEBUG MARKER: phase 2 [ 3897.444293] Lustre: DEBUG MARKER: == replay-single test 68: AT: verify slowing locks ======= 13:07:41 (1761325661) [ 3921.649077] LustreError: 14192:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 sleeping for 19000ms [ 3940.688073] LustreError: 14192:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 awake [ 3940.716656] LustreError: 33604:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 sleeping for 25000ms [ 3965.784134] LustreError: 33604:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 awake [ 3968.601632] Lustre: DEBUG MARKER: == replay-single test 70a: check multi client t-f ======== 13:08:52 (1761325732) [ 3969.134246] Lustre: DEBUG MARKER: SKIP: replay-single test_70a Need two or more clients, have 1 [ 3969.727792] Lustre: DEBUG MARKER: == replay-single test 70b: dbench 2mdts recovery; 1 clients ========================================================== 13:08:54 (1761325734) [ 3971.537219] Lustre: DEBUG MARKER: Started rundbench load pid=138234 ... [ 3975.294215] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3976.859593] Lustre: DEBUG MARKER: test_70b fail mds1 1 times [ 3977.643256] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation mds_readpage to node 192.168.202.136@tcp failed: rc = -19 [ 3989.472133] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 3989.475288] LustreError: Skipped 11 previous similar messages [ 3995.615217] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72bff8f4 to 0x3e67870b72c0d902 [ 3995.618455] Lustre: Skipped 10 previous similar messages [ 4001.913992] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4002.541781] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4007.628306] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 4009.192421] Lustre: DEBUG MARKER: test_70b fail mds2 2 times [ 4032.124178] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 4032.729826] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4037.655576] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 4039.182585] Lustre: DEBUG MARKER: test_70b fail mds1 3 times [ 4039.883371] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation mds_close to node 192.168.202.136@tcp failed: rc = -19 [ 4064.227064] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 4064.231114] Lustre: Skipped 11 previous similar messages [ 4071.480141] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4072.047065] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4076.969494] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 4078.473992] Lustre: DEBUG MARKER: test_70b fail mds2 4 times [ 4100.588628] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 4101.142912] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4117.040979] Lustre: DEBUG MARKER: == replay-single test 70c: tar 2mdts recovery ============ 13:11:21 (1761325881) [ 4240.184057] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 4250.691409] Lustre: DEBUG MARKER: test_70c fail mds1 1 times [ 4251.688488] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation ldlm_enqueue to node 192.168.202.136@tcp failed: rc = -107 [ 4251.692306] Lustre: lustre-MDT0000-mdc-ffff8dafc80d5800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4251.696590] Lustre: Skipped 7 previous similar messages [ 4260.960093] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761326018/real 1761326018] req@00000000677de124 x1846879823127104/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761326025 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 4260.967745] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 4276.721023] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@00000000eb2aa1cb x1846879816330880/t330712501884(330712501884) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 608/600 e 0 to 0 dl 1761326048 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'lfs.0' [ 4276.728569] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 245 previous similar messages [ 4285.156115] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4285.752763] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4409.877299] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 4420.378873] Lustre: DEBUG MARKER: test_70c fail mds2 2 times [ 4421.318133] LustreError: 11-0: lustre-MDT0001-mdc-ffff8dafc80d5800: operation mds_reint to node 192.168.202.136@tcp failed: rc = -107 [ 4447.244646] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 4447.776019] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4461.901641] Lustre: DEBUG MARKER: == replay-single test 70d: mkdir/rmdir striped dir 2mdts recovery ========================================================== 13:17:06 (1761326226) [ 4584.918514] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 4595.407670] Lustre: DEBUG MARKER: test_70d fail mds2 1 times [ 4618.827258] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 4619.382740] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4743.616606] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 4754.123991] Lustre: DEBUG MARKER: test_70d fail mds1 2 times [ 4754.923362] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc80d5800: operation ldlm_enqueue to node 192.168.202.136@tcp failed: rc = -19 [ 4766.368154] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 4766.372578] LustreError: Skipped 2 previous similar messages [ 4772.834059] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b72e18377 to 0x3e67870b7311e3ff [ 4772.837013] Lustre: Skipped 2 previous similar messages [ 4772.838587] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 4772.840943] Lustre: Skipped 6 previous similar messages [ 4780.511428] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4781.065379] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4784.784498] Lustre: DEBUG MARKER: == replay-single test 70e: rename cross-MDT with random fails ========================================================== 13:22:29 (1761326549) [ 4907.718498] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 4918.244369] Lustre: DEBUG MARKER: test_70e fail mds2 1 times [ 4921.316631] Lustre: lustre-MDT0001-mdc-ffff8dafc80d5800: Connection to lustre-MDT0001 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4921.323848] Lustre: Skipped 3 previous similar messages [ 4935.811110] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@0000000000753ea4 x1846879843523328/t21474851907(21474851907) o101->lustre-MDT0001-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 648/600 e 0 to 0 dl 1761326707 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'lfs.0' [ 4935.822318] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 670 previous similar messages [ 4942.440362] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 4943.113485] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5067.903319] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5078.487062] Lustre: DEBUG MARKER: test_70e fail mds2 2 times [ 5101.816135] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5102.514645] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5106.613356] Lustre: DEBUG MARKER: == replay-single test 70f: OSS O_DIRECT recovery with 1 clients ========================================================== 13:27:50 (1761326870) [ 5113.237407] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 5114.793845] Lustre: DEBUG MARKER: test_70f failing OST 1 times [ 5117.408168] Lustre: 2268:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761326875/real 1761326875] req@00000000cf3abb3e x1846879850677696/t0(0) o4->lustre-OST0000-osc-ffff8dafc80d5800@192.168.202.136@tcp:6/4 lens 488/448 e 0 to 1 dl 1761326882 ref 2 fl Rpc:XQr/0/ffffffff rc 0/-1 job:'dd.0' [ 5117.416973] Lustre: 2268:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 5137.313553] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5137.987387] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5147.627900] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 5149.351317] Lustre: DEBUG MARKER: test_70f failing OST 2 times [ 5170.918462] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5171.507602] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5177.806118] Lustre: DEBUG MARKER: == replay-single test 71a: mkdir/rmdir striped dir with 2 mdts recovery ========================================================== 13:29:02 (1761326942) [ 5300.846367] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5303.324481] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5313.841763] Lustre: DEBUG MARKER: fail mds2 mds1 1 times [ 5314.663842] LustreError: 11-0: lustre-MDT0001-mdc-ffff8dafc80d5800: operation ldlm_enqueue to node 192.168.202.136@tcp failed: rc = -107 [ 5452.769768] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b7311e3ff to 0x3e67870b733ae424 [ 5452.772670] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 5452.774671] Lustre: Skipped 4 previous similar messages [ 5466.926928] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5467.440958] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5467.945394] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5471.073807] Lustre: DEBUG MARKER: == replay-single test 73a: open(O_CREAT), unlink, replay, reconnect before open replay, close ========================================================== 13:33:55 (1761327235) [ 5473.516494] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5484.512144] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 5484.515433] LustreError: Skipped 1 previous similar message [ 5497.824152] LustreError: 2267:0:(client.c:3110:ptlrpc_replay_interpret()) @@@ request replay timed out req@00000000708b908a x1846879850877888/t339302454414(339302454414) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 648/600 e 0 to 1 dl 1761327262 ref 2 fl Interpret:EXPQU/4/ffffffff rc -110/-1 job:'lfs.0' [ 5499.761560] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5500.406172] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5503.875302] Lustre: DEBUG MARKER: == replay-single test 73b: open(O_CREAT), unlink, replay, reconnect at open_replay reply, close ========================================================== 13:34:28 (1761327268) [ 5506.264961] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5532.576151] LustreError: 2267:0:(client.c:3110:ptlrpc_replay_interpret()) @@@ request replay timed out req@00000000708b908a x1846879850877888/t339302454414(339302454414) o101->lustre-MDT0000-mdc-ffff8dafc80d5800@192.168.202.136@tcp:12/10 lens 648/600 e 0 to 1 dl 1761327297 ref 2 fl Interpret:EXPQU/4/ffffffff rc -110/-1 job:'lfs.0' [ 5534.249108] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5534.735031] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5538.111859] Lustre: DEBUG MARKER: == replay-single test 74: Ensure applications don't fail waiting for OST recovery ========================================================== 13:35:02 (1761327302) [ 5538.914141] Lustre: Unmounted lustre-client [ 5559.388673] LustreError: 11-0: lustre-MDT0000-mdc-ffff8dafc8a83800: operation mds_connect to node 192.168.202.136@tcp failed: rc = -16 [ 5564.906272] Lustre: Mounted lustre-client [ 5573.683494] Lustre: DEBUG MARKER: == replay-single test 80a: DNE: create remote dir, drop update rep from MDT0, fail MDT0 ========================================================== 13:35:37 (1761327337) [ 5576.435813] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5580.258204] Lustre: lustre-MDT0000-mdc-ffff8dafc8a83800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5580.263391] Lustre: Skipped 7 previous similar messages [ 5602.938959] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@000000008d85fb37 x1846879853829120/t356482285574(356482285574) o101->lustre-MDT0000-mdc-ffff8dafc8a83800@192.168.202.136@tcp:12/10 lens 648/600 e 0 to 0 dl 1761327443 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'lfs.0' [ 5602.957886] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 6 previous similar messages [ 5608.223758] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5608.945224] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5612.980238] Lustre: DEBUG MARKER: == replay-single test 80b: DNE: create remote dir, drop update rep from MDT0, fail MDT1 ========================================================== 13:36:17 (1761327377) [ 5616.304799] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5619.722945] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5643.379684] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5643.908772] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5647.888793] Lustre: DEBUG MARKER: == replay-single test 80c: DNE: create remote dir, drop update rep from MDT1, fail MDT[0,1] ========================================================== 13:36:52 (1761327412) [ 5651.597575] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5654.321432] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5687.415699] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5687.968270] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5712.882793] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5713.429671] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5717.511792] Lustre: DEBUG MARKER: == replay-single test 80d: DNE: create remote dir, drop update rep from MDT1, fail 2 MDTs ========================================================== 13:38:01 (1761327481) [ 5723.729418] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5726.441501] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5738.976131] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761327496/real 1761327496] req@000000006351b949 x1846879853882240/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761327503 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 5738.990013] Lustre: 2270:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 5787.200887] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5787.755841] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5788.362997] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5792.194622] Lustre: DEBUG MARKER: == replay-single test 80e: DNE: create remote dir, drop MDT1 rep, fail MDT0 ========================================================== 13:39:16 (1761327556) [ 5798.799922] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5824.872101] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5825.370569] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5828.941882] Lustre: DEBUG MARKER: == replay-single test 80f: DNE: create remote dir, drop MDT1 rep, fail MDT1 ========================================================== 13:39:53 (1761327593) [ 5831.624548] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5853.564405] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5854.044103] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5857.385878] Lustre: DEBUG MARKER: == replay-single test 80g: DNE: create remote dir, drop MDT1 rep, fail MDT0, then MDT1 ========================================================== 13:40:21 (1761327621) [ 5863.010515] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5865.376071] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5888.265707] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5889.099927] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5915.683381] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5916.464802] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5921.054157] Lustre: DEBUG MARKER: == replay-single test 80h: DNE: create remote dir, drop MDT1 rep, fail 2 MDTs ========================================================== 13:41:25 (1761327685) [ 5928.019569] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5931.376377] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5973.491680] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5974.028615] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5974.518933] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5977.992053] Lustre: DEBUG MARKER: == replay-single test 81a: DNE: unlink remote dir, drop MDT0 update rep, fail MDT1 ========================================================== 13:42:22 (1761327742) [ 5980.704705] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5981.302204] LustreError: 11-0: lustre-MDT0001-mdc-ffff8dafc8a83800: operation mds_reint to node 192.168.202.136@tcp failed: rc = -19 [ 5981.307010] LustreError: Skipped 2 previous similar messages [ 6008.233511] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6008.786880] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6012.107749] Lustre: DEBUG MARKER: == replay-single test 81b: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0 ========================================================== 13:42:56 (1761327776) [ 6014.735200] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6047.819880] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6048.497973] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6052.048615] Lustre: DEBUG MARKER: == replay-single test 81c: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0,MDT1 ========================================================== 13:43:36 (1761327816) [ 6055.242775] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6057.669487] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6075.345740] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b733c89eb to 0x3e67870b733c915b [ 6075.349961] Lustre: Skipped 9 previous similar messages [ 6075.352230] Lustre: MGC192.168.202.136@tcp: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 6075.354140] Lustre: Skipped 30 previous similar messages [ 6080.862419] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6081.353783] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6104.845806] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6105.297211] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6108.562992] Lustre: DEBUG MARKER: == replay-single test 81d: DNE: unlink remote dir, drop MDT0 update reply, fail 2 MDTs ========================================================== 13:44:32 (1761327872) [ 6111.146828] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6114.353468] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6122.464152] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 6122.468046] LustreError: Skipped 9 previous similar messages [ 6171.956113] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6172.484314] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6172.999818] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6176.307017] Lustre: DEBUG MARKER: == replay-single test 81e: DNE: unlink remote dir, drop MDT1 req reply, fail MDT0 ========================================================== 13:45:40 (1761327940) [ 6179.191484] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6184.928147] Lustre: lustre-MDT0001-mdc-ffff8dafc8a83800: Connection to lustre-MDT0001 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6184.931993] Lustre: Skipped 21 previous similar messages [ 6203.765393] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6204.280985] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6207.594946] Lustre: DEBUG MARKER: == replay-single test 81f: DNE: unlink remote dir, drop MDT1 req reply, fail MDT1 ========================================================== 13:46:11 (1761327971) [ 6210.495466] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6231.792215] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6232.274272] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6235.317262] Lustre: DEBUG MARKER: == replay-single test 81g: DNE: unlink remote dir, drop req reply, fail M0, then M1 ========================================================== 13:46:39 (1761327999) [ 6237.928193] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6240.257906] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6265.671437] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6266.202460] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6289.264498] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6289.781398] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6293.066879] Lustre: DEBUG MARKER: == replay-single test 81h: DNE: unlink remote dir, drop request reply, fail 2 MDTs ========================================================== 13:47:37 (1761328057) [ 6295.674521] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6297.954235] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6339.884058] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6340.345070] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6340.774376] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6343.790415] Lustre: DEBUG MARKER: == replay-single test 84a: stale open during export disconnect ========================================================== 13:48:28 (1761328108) [ 6345.565195] LustreError: lustre-MDT0000-mdc-ffff8dafc8a83800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 6345.568579] LustreError: 258479:0:(file.c:5205:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000007:0x1:0x0] error: rc = -5 [ 6348.590743] Lustre: DEBUG MARKER: == replay-single test 85a: check the cancellation of unused locks during recovery(IBITS) ========================================================== 13:48:33 (1761328113) [ 6361.056453] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1761328118/real 1761328118] req@000000003038a725 x1846879854076672/t0(0) o400->MGC192.168.202.136@tcp@192.168.202.136@tcp:26/25 lens 224/224 e 0 to 1 dl 1761328125 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:3.0' [ 6361.068200] Lustre: 2269:0:(client.c:2295:ptlrpc_expire_one_request()) Skipped 21 previous similar messages [ 6367.220738] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@0000000090a67f11 x1846879854025728/t408021893132(408021893132) o101->lustre-MDT0000-mdc-ffff8dafc8a83800@192.168.202.136@tcp:12/10 lens 576/600 e 0 to 0 dl 1761328139 ref 2 fl Interpret:RPQU/4/0 rc 301/301 job:'grep.0' [ 6367.233310] LustreError: 2267:0:(client.c:3161:ptlrpc_replay_interpret()) Skipped 1 previous similar message [ 6373.136809] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6373.597439] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6376.670108] Lustre: DEBUG MARKER: == replay-single test 85b: check the cancellation of unused locks during recovery(EXTENT) ========================================================== 13:49:01 (1761328141) [ 6397.095704] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6397.565767] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6400.822904] Lustre: DEBUG MARKER: == replay-single test 86: umount server after clear nid_stats should not hit LBUG ========================================================== 13:49:25 (1761328165) [ 6401.219994] Lustre: Unmounted lustre-client [ 6411.241934] Lustre: Mounted lustre-client [ 6413.090519] Lustre: DEBUG MARKER: == replay-single test 87a: write replay ================== 13:49:37 (1761328177) [ 6415.547390] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 6434.546311] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6435.039511] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6438.308762] Lustre: DEBUG MARKER: == replay-single test 87b: write replay with changed data (checksum resend) ========================================================== 13:50:02 (1761328202) [ 6442.151883] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 6462.522911] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6463.030656] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6466.207928] Lustre: DEBUG MARKER: == replay-single test 88: MDS should not assign same objid to different files ========================================================== 13:50:30 (1761328230) [ 6468.406469] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 6470.554932] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6512.071962] Lustre: DEBUG MARKER: == replay-single test 89: no disk space leak on late ost connection ========================================================== 13:51:16 (1761328276) [ 6540.068171] Lustre: Unmounted lustre-client [ 6545.597667] Lustre: Mounted lustre-client [ 6545.613501] LustreError: 11-0: lustre-OST0000-osc-ffff8dafc891e800: operation ost_connect to node 192.168.202.136@tcp failed: rc = -16 [ 6545.617382] LustreError: Skipped 4 previous similar messages [ 6618.014083] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 68 sec [ 6624.698387] Lustre: DEBUG MARKER: free_before: 7646580 free_after: 7646580 [ 6627.358340] Lustre: DEBUG MARKER: == replay-single test 90: lfs find identifies the missing striped file segments ========================================================== 13:53:11 (1761328391) [ 6651.185369] Lustre: DEBUG MARKER: == replay-single test 93a: replay + reconnect ============ 13:53:35 (1761328415) [ 6709.498478] Lustre: lustre-OST0000-osc-ffff8dafc891e800: Connection restored to 192.168.202.136@tcp (at 192.168.202.136@tcp) [ 6709.503157] Lustre: Skipped 27 previous similar messages [ 6712.291344] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6713.014125] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6717.328239] Lustre: DEBUG MARKER: == replay-single test 93b: replay + reconnect on mds ===== 13:54:41 (1761328481) [ 6727.136311] LustreError: 166-1: MGC192.168.202.136@tcp: Connection to MGS (at 192.168.202.136@tcp) was lost; in progress operations using this service will fail [ 6727.142668] LustreError: Skipped 6 previous similar messages [ 6743.522685] Lustre: Evicted from MGS (at 192.168.202.136@tcp) after server handle changed from 0x3e67870b733d40cb to 0x3e67870b733d4ea1 [ 6743.528328] Lustre: Skipped 7 previous similar messages [ 6830.749567] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6831.496073] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6835.618419] Lustre: DEBUG MARKER: == replay-single test complete, duration 6667 sec ======== 13:56:39 (1761328599) [ 6842.850569] Lustre: lustre-MDT0000-mdc-ffff8dafc891e800: Connection to lustre-MDT0000 (at 192.168.202.136@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6842.858599] Lustre: Skipped 18 previous similar messages [ 6870.734275] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6871.416575] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6873.165129] Lustre: Unmounted lustre-client [ 6901.630093] Key type lgssc unregistered [ 6901.763738] LNet: 275435:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6902.816790] LNet: Removed LNI 192.168.202.36@tcp [ 6903.093404] Key type .llcrypt unregistered [ 6903.094899] Key type ._llcrypt unregistered