[ 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 502909273 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 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-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, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001013] APIC: Switch to symmetric I/O mode setup [ 0.002303] x2apic enabled [ 0.003006] Switched APIC routing to physical x2apic. [ 0.004010] kvm-guest: setup PV IPIs [ 0.006663] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007020] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008011] pid_max: default: 32768 minimum: 301 [ 0.009143] LSM: Security Framework initializing [ 0.010043] Yama: becoming mindful. [ 0.011028] SELinux: Initializing. [ 0.012209] *** VALIDATE selinux *** [ 0.020535] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.024169] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.025116] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.026101] *** VALIDATE tmpfs *** [ 0.027426] *** VALIDATE proc *** [ 0.029078] *** VALIDATE cgroup *** [ 0.029878] *** VALIDATE cgroup2 *** [ 0.030193] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.031135] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.032004] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.033021] Spectre V2 : User space: Vulnerable [ 0.034006] Speculative Store Bypass: Vulnerable [ 0.037234] debug: unmapping init [mem 0xffffffff8ea59000-0xffffffff8ea60fff] [ 0.039777] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.040713] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.041022] ... version: 2 [ 0.041901] ... bit width: 48 [ 0.042018] ... generic registers: 4 [ 0.043012] ... value mask: 0000ffffffffffff [ 0.044014] ... max period: 00007fffffffffff [ 0.044951] ... fixed-purpose events: 3 [ 0.045013] ... event mask: 000000070000000f [ 0.046291] rcu: Hierarchical SRCU implementation. [ 0.048310] smp: Bringing up secondary CPUs ... [ 0.049497] x86: Booting SMP configuration: [ 0.050022] .... node #0, CPUs: #1 #2 #3 [ 0.053293] smp: Brought up 1 node, 4 CPUs [ 0.054862] smpboot: Max logical packages: 1 [ 0.055013] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.221503] node 0 deferred pages initialised in 164ms [ 0.225118] devtmpfs: initialized [ 0.226489] x86/mm: Memory block size: 128MB [ 0.230223] gcov: version magic: 0x41383552 [ 0.232311] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.235065] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.237417] pinctrl core: initialized pinctrl subsystem [ 0.239290] [ 0.239819] ************************************************************* [ 0.243014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.245008] ** ** [ 0.247010] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.249009] ** ** [ 0.250009] ** This means that this kernel is built to expose internal ** [ 0.252009] ** IOMMU data structures, which may compromise security on ** [ 0.254010] ** your system. ** [ 0.256009] ** ** [ 0.259008] ** If you see this message and you are not debugging the ** [ 0.261008] ** kernel, report this immediately to your vendor! ** [ 0.263009] ** ** [ 0.265009] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.268009] ************************************************************* [ 0.270809] NET: Registered protocol family 16 [ 0.272481] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.275047] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.277042] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.280095] cpuidle: using governor menu [ 0.282008] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.284511] PCI: Using configuration type 1 for base access [ 0.287129] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.296972] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.297000] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.304108] cryptd: max_cpu_qlen set to 1000 [ 0.306766] ACPI: Added _OSI(Module Device) [ 0.307010] ACPI: Added _OSI(Processor Device) [ 0.308000] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.308009] ACPI: Added _OSI(Processor Aggregator Device) [ 0.309000] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.316050] ACPI: Interpreter enabled [ 0.317041] ACPI: PM: (supports S0 S3 S4 S5) [ 0.318008] ACPI: Using IOAPIC for interrupt routing [ 0.319096] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.322415] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.332000] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.334026] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.337011] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.340072] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.344341] acpiphp: Slot [2] registered [ 0.346123] acpiphp: Slot [3] registered [ 0.348078] acpiphp: Slot [4] registered [ 0.349078] acpiphp: Slot [5] registered [ 0.351145] acpiphp: Slot [6] registered [ 0.353093] acpiphp: Slot [7] registered [ 0.354095] acpiphp: Slot [8] registered [ 0.355185] acpiphp: Slot [9] registered [ 0.357066] acpiphp: Slot [10] registered [ 0.359485] acpiphp: Slot [11] registered [ 0.360060] acpiphp: Slot [12] registered [ 0.362073] acpiphp: Slot [13] registered [ 0.363061] acpiphp: Slot [14] registered [ 0.364078] acpiphp: Slot [15] registered [ 0.365066] acpiphp: Slot [16] registered [ 0.366107] acpiphp: Slot [17] registered [ 0.367069] acpiphp: Slot [18] registered [ 0.368114] acpiphp: Slot [19] registered [ 0.369074] acpiphp: Slot [20] registered [ 0.371098] acpiphp: Slot [21] registered [ 0.372064] acpiphp: Slot [22] registered [ 0.373085] acpiphp: Slot [23] registered [ 0.374079] acpiphp: Slot [24] registered [ 0.376071] acpiphp: Slot [25] registered [ 0.377092] acpiphp: Slot [26] registered [ 0.378058] acpiphp: Slot [27] registered [ 0.379078] acpiphp: Slot [28] registered [ 0.381072] acpiphp: Slot [29] registered [ 0.382061] acpiphp: Slot [30] registered [ 0.383061] acpiphp: Slot [31] registered [ 0.384061] PCI host bridge to bus 0000:00 [ 0.385012] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.386011] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.387000] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.387012] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.388000] pci_bus 0000:00: root bus resource [mem 0x180000000-0x1ffffffff window] [ 0.390022] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.391142] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.395281] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.398139] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.405535] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.409048] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.411012] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.413012] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.416016] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.418429] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.420700] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.425046] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.428534] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.431654] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.440639] pci 0000:00:02.0: reg 0x20: [mem 0xfebf4000-0xfebf7fff 64bit pref] [ 0.445014] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.454323] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.462019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.471024] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.492022] pci 0000:00:05.0: reg 0x20: [mem 0xfebf8000-0xfebfbfff 64bit pref] [ 0.502000] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.508014] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.514017] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.528015] pci 0000:00:06.0: reg 0x20: [mem 0xfebfc000-0xfebfffff 64bit pref] [ 0.540157] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.542321] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.544416] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.546366] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.549201] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.553089] iommu: Default domain type: Passthrough [ 0.555007] SCSI subsystem initialized [ 0.557148] ACPI: bus type USB registered [ 0.559107] usbcore: registered new interface driver usbfs [ 0.560058] usbcore: registered new interface driver hub [ 0.562091] usbcore: registered new device driver usb [ 0.564172] pps_core: LinuxPPS API ver. 1 registered [ 0.566008] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.569055] PTP clock support registered [ 0.571710] EDAC MC: Ver: 3.0.0 [ 0.574162] PCI: Using ACPI for IRQ routing [ 0.575000] NetLabel: Initializing [ 0.575000] NetLabel: domain hash size = 128 [ 0.575005] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.576000] NetLabel: unlabeled traffic allowed by default [ 0.578108] vgaarb: loaded [ 0.580038] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.581007] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.589000] clocksource: Switched to clocksource kvm-clock [ 0.698231] VFS: Disk quotas dquot_6.6.0 [ 0.699602] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.701605] *** VALIDATE ramfs *** [ 0.702483] *** VALIDATE hugetlbfs *** [ 0.703759] pnp: PnP ACPI init [ 0.706083] pnp: PnP ACPI: found 6 devices [ 0.724201] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.726816] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.728361] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.731345] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.733331] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.735257] pci_bus 0000:00: resource 8 [mem 0x180000000-0x1ffffffff window] [ 0.737122] NET: Registered protocol family 2 [ 0.739290] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.743694] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.746104] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.750636] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.753452] TCP: Hash tables configured (established 65536 bind 65536) [ 0.755786] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.758522] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.760951] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.763783] NET: Registered protocol family 1 [ 0.767382] RPC: Registered named UNIX socket transport module. [ 0.769467] RPC: Registered udp transport module. [ 0.771178] RPC: Registered tcp transport module. [ 0.772583] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.774592] NET: Registered protocol family 44 [ 0.776152] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.777995] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.779887] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.782423] PCI: CLS 0 bytes, default 64 [ 0.783801] Unpacking initramfs... [ 2.616069] debug: unmapping init [mem 0xffff990b7cc64000-0xffff990b7ffcffff] [ 2.620667] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.622561] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.625107] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.244393] Initialise system trusted keyrings [ 3.245553] Key type blacklist registered [ 3.247638] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.255512] zbud: loaded [ 3.258754] *** VALIDATE nfs *** [ 3.259757] *** VALIDATE nfs4 *** [ 3.261275] pstore: using deflate compression [ 3.264610] Platform Keyring initialized [ 3.390178] NET: Registered protocol family 38 [ 3.391537] Key type asymmetric registered [ 3.392693] Asymmetric key parser 'x509' registered [ 3.394225] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.396885] io scheduler mq-deadline registered [ 3.398581] io scheduler kyber registered [ 3.400193] io scheduler bfq registered [ 3.405275] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.407604] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.413555] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.416239] ACPI: Power Button [PWRF] [ 3.545384] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.686329] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.850163] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.880304] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.912252] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.924699] Non-volatile memory driver v1.3 [ 3.929122] Linux agpgart interface v0.103 [ 3.965123] virtio_blk virtio1: [vda] 134040 512-byte logical blocks (68.6 MB/65.4 MiB) [ 3.967992] vda: detected capacity change from 0 to 68628480 [ 3.999425] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 4.003397] vdb: detected capacity change from 0 to 1073741824 [ 4.010201] libphy: Fixed MDIO Bus: probed [ 4.018087] usbcore: registered new interface driver usbserial_generic [ 4.020336] usbserial: USB Serial support registered for generic [ 4.022397] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 4.027757] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 4.030630] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 4.032680] mousedev: PS/2 mouse device common for all mice [ 4.035467] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 4.038486] rtc_cmos 00:05: RTC can wake from S4 [ 4.047711] rtc_cmos 00:05: registered as rtc0 [ 4.049590] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 4.051477] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 4.056685] intel_pstate: CPU model not supported [ 4.062354] hid: raw HID events driver (C) Jiri Kosina [ 4.067568] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 4.073456] usbcore: registered new interface driver usbhid [ 4.074888] usbhid: USB HID core driver [ 4.077779] drop_monitor: Initializing network drop monitor service [ 4.079622] Initializing XFRM netlink socket [ 4.082349] NET: Registered protocol family 10 [ 4.086048] Segment Routing with IPv6 [ 4.087173] NET: Registered protocol family 17 [ 4.089598] mpls_gso: MPLS GSO support [ 4.095804] RAS: Correctable Errors collector initialized. [ 4.097394] AVX version of gcm_enc/dec engaged. [ 4.098564] AES CTR mode by8 optimization enabled [ 4.291086] sched_clock: Marking stable (4291062765, 0)->(5263466819, -972404054) [ 4.296951] registered taskstats version 1 [ 4.299914] Loading compiled-in X.509 certificates [ 4.303902] zswap: loaded using pool lzo/zbud [ 4.361327] Key type big_key registered [ 4.385994] Key type encrypted registered [ 4.387847] ima: No TPM chip found, activating TPM-bypass! [ 4.389713] ima: Allocated hash algorithm: sha1 [ 4.391243] ima: No architecture policies found [ 4.392570] evm: Initialising EVM extended attributes: [ 4.394544] evm: security.selinux [ 4.395665] evm: security.ima [ 4.396759] evm: security.capability [ 4.402433] evm: HMAC attrs: 0x1 [ 4.405973] rtc_cmos 00:05: setting system clock to 2025-12-29 18:54:56 UTC (1767034496) [ 4.413970] debug: unmapping init [mem 0xffffffff8fa03000-0xffffffff8fbfffff] [ 4.416743] debug: unmapping init [mem 0xffffffff8e782000-0xffffffff8ea58fff] [ 4.425677] Write protecting the kernel read-only data: 28672k [ 4.429078] debug: unmapping init [mem 0xffffffff8ce03000-0xffffffff8cffffff] [ 4.431359] debug: unmapping init [mem 0xffffffff8d714000-0xffffffff8d7fffff] [ 4.487967] 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) [ 4.499838] systemd[1]: Detected virtualization kvm. [ 4.503199] systemd[1]: Detected architecture x86-64. [ 4.505029] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.546393] systemd[1]: No hostname configured. [ 4.547852] systemd[1]: Set hostname to . [ 4.549738] random: systemd: uninitialized urandom read (16 bytes read) [ 4.552606] systemd[1]: Initializing machine ID from random generator. [ 4.667488] random: ln: uninitialized urandom read (6 bytes read) [ 4.877359] random: systemd: uninitialized urandom read (16 bytes read) [ 4.880560] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 4.891741] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 4.898401] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ OK ] Reached target Swap. [ OK ] Reached target Local File Systems. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Slices. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... Starting Setup Virtual Console... Starting Journal Service... [ OK ] Reached target Sockets. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 6.348864] device-mapper: uevent: version 1.0.3 [ 6.354253] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ 8.022619] virtio_net virtio0 ens2: renamed from eth0 [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 8.466390] scsi host0: ata_piix [ 8.479906] scsi host1: ata_piix [ 8.482393] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 8.487319] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 10.657162] random: fast init done [ 13.929720] random: crng init done [ 13.934938] random: 7 urandom warning(s) missed due to ratelimiting [ 14.019405] dracut-initqueue[584]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 15.576597] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 17.195976] printk: systemd: 26 output lines suppressed due to ratelimiting [ 17.740104] SELinux: Disabled at runtime. [ 17.849516] 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) [ 17.873858] systemd[1]: Detected virtualization kvm. [ 17.879975] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 19.045424] systemd[1]: initrd-switch-root.service: Succeeded. [ 19.049266] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 19.075362] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 19.088626] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 19.100281] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 19.119834] systemd[1]: Starting Journal Service... Starting Journal Service... [ 19.185594] systemd[1]: Listening on Process Core Dump Socket. [ OK ] Listening on Process Core Dump Socket. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Created slice system-getty.slice. [ OK ] Stopped target Switch Root. Mounting POSIX Message Queue File System... [ OK ] Listening on RPCbind Server Activation Socket. Mounting Huge Pages File System... [ OK ] Reached target rpc_pipefs.target. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on udev Kernel Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. Starting Remount Root and Kernel File Systems... [ OK ] Created slice User and Session Slice. [ OK ] Reached target RPC Port Mapper. Activating swap /dev/disk/by-label/SWAP... [ 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. Starting udev Coldplug all Devices... [ 19.828888] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Reached target Slices. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. Mounting Kernel Debug File System... [ OK ] Started Journal Service. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ 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. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 20.983811] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 21.955834] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 21.961838] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 22.376438] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 22.459173] EDAC sbridge: Ver: 1.1.2 [ 25.573601] Key type dns_resolver registered [ 26.080391] NFS: Registering the id_resolver key type [ 26.082223] Key type id_resolver registered [ 26.083479] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started daily update of the root trust anchor for DNSSEC. Starting Restore /run/initramfs on shutdown... [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started irqbalance daemon. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Hostname Service... [ 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 Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started OpenSSH server daemon. [ 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. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg327-client login: [ 55.928697] libcfs: loading out-of-tree module taints kernel. [ 56.015458] Key type ._llcrypt registered [ 56.019700] Key type .llcrypt registered [ 56.195268] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 56.200429] alg: No test for adler32 (adler32-zlib) [ 57.142754] Lustre: Lustre: Build Version: 2.17.0_RC3_1_ga0d6154 [ 57.391452] LNet: Added LNI 192.168.203.27@tcp [8/256/0/180] [ 58.999115] Key type lgssc registered [ 59.504466] Lustre: Echo OBD driver; http://www.lustre.org/ [ 119.143352] Lustre: Mounted lustre-client [ 123.044487] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 138.601446] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing check_logdir /tmp/testlogs/ [ 142.167769] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing yml_node [ 144.871224] Lustre: lustre-OST0000-osc-ffff990bc2ced000: disconnect after 23s idle [ 146.533403] Lustre: DEBUG MARKER: Client: 2.17.0.RC3 [ 148.519777] Lustre: DEBUG MARKER: MDS: 2.17.0.RC3 [ 149.812058] Lustre: DEBUG MARKER: OSS: 2.17.0.RC3 [ 150.532177] Lustre: DEBUG MARKER: -----============= acceptance-small: replay-single ============----- Mon Dec 29 13:57:22 EST 2025 [ 157.905166] Lustre: DEBUG MARKER: excepting tests: 59 36 [ 158.635338] Lustre: DEBUG MARKER: === replay-single: start setup 13:57:30 (1767034650) === [ 160.079535] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing check_config_client /mnt/lustre [ 168.948313] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 174.561916] Lustre: DEBUG MARKER: === replay-single: finish setup 13:57:46 (1767034666) === [ 175.273153] Lustre: DEBUG MARKER: == replay-single test 0a: empty replay =================== 13:57:46 (1767034666) [ 178.572897] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 180.705746] Lustre: lustre-MDT0000-mdc-ffff990bc2ced000: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 196.063564] Lustre: 2404:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767034672/real 1767034672] req@ffff990bd14f8e00 x1852870019266688/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767034688 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 196.064563] Lustre: lustre-OST0000-osc-ffff990bc2ced000: disconnect after 21s idle [ 196.072342] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 196.074781] Lustre: Skipped 1 previous similar message [ 196.082993] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b2b91 to 0xe79bd7b01d7b2f9d [ 196.088545] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 200.753094] Lustre: lustre-MDT0000-mdc-ffff990bc2ced000: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 202.613418] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 203.591971] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 208.367445] Lustre: DEBUG MARKER: == replay-single test 0b: ensure object created after recover exists. (3284) ========================================================== 13:58:19 (1767034699) [ 211.430476] Lustre: lustre-OST0000-osc-ffff990bc2ced000: Connection to lustre-OST0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 225.729440] Lustre: lustre-OST0000-osc-ffff990bc2ced000: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 226.783184] Lustre: lustre-OST0001-osc-ffff990bc2ced000: disconnect after 21s idle [ 226.789579] Lustre: Skipped 1 previous similar message [ 230.533200] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 231.175504] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 235.773651] Lustre: DEBUG MARKER: == replay-single test 0c: check replay-barrier =========== 13:58:47 (1767034727) [ 239.021396] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 239.058846] LustreError: 13686:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bc2ced000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 239.069079] LustreError: 13686:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [ 239.098932] Lustre: Unmounted lustre-client [ 258.053089] LustreError: lustre-MDT0000-mdc-ffff990bc2d7c800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 263.147331] LustreError: lustre-MDT0000-mdc-ffff990bc2d7c800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 268.271296] LustreError: lustre-MDT0000-mdc-ffff990bc2d7c800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 273.388765] LustreError: lustre-MDT0000-mdc-ffff990bc2d7c800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 278.508130] LustreError: lustre-MDT0000-mdc-ffff990bc2d7c800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 288.751524] LustreError: lustre-MDT0000-mdc-ffff990bc2d7c800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 288.755137] LustreError: Skipped 1 previous similar message [ 309.228237] LustreError: lustre-MDT0000-mdc-ffff990bc2d7c800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 309.233548] LustreError: Skipped 3 previous similar messages [ 329.770127] Lustre: Mounted lustre-client [ 335.546484] Lustre: DEBUG MARKER: == replay-single test 0d: expired recovery with no clients ========================================================== 14:00:26 (1767034826) [ 340.229609] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 340.268087] LustreError: 14753:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bc2d7c800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 340.273653] LustreError: 14753:0:(lov_obd.c:783:lov_cleanup()) Skipped 1 previous similar message [ 340.288303] LustreError: 14753:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [ 340.291024] LustreError: 14753:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 340.329813] Lustre: Unmounted lustre-client [ 373.028370] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 373.032857] LustreError: Skipped 3 previous similar messages [ 439.790193] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_connect to node 192.168.203.127@tcp failed: rc = -16 [ 439.797502] LustreError: Skipped 12 previous similar messages [ 444.926988] Lustre: Mounted lustre-client [ 450.206961] Lustre: DEBUG MARKER: == replay-single test 1: simple create =================== 14:02:21 (1767034941) [ 454.258870] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 460.258769] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 475.624522] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 475.633726] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b3fe2 to 0xe79bd7b01d7b4465 [ 475.642775] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 477.589252] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 478.292764] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 482.495250] Lustre: DEBUG MARKER: == replay-single test 2a: touch ========================== 14:02:53 (1767034973) [ 485.884598] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 490.977617] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 506.339922] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 506.348708] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b4465 to 0xe79bd7b01d7b4974 [ 506.353545] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 506.357126] Lustre: Skipped 1 previous similar message [ 507.410731] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bd8a51c00 x1852870019338496/t21474836484(21474836484) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767035015 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'touch.0' uid:0 gid:0 projid:0 [ 508.876836] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 509.714443] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 513.675444] Lustre: DEBUG MARKER: == replay-single test 2b: touch ========================== 14:03:25 (1767035005) [ 516.706591] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 521.702042] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 537.055146] Lustre: 2403:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035013/real 1767035013] req@ffff990bd14f9880 x1852870019349376/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035029 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 537.059257] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 537.076140] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b4974 to 0xe79bd7b01d7b4ebb [ 537.081536] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 537.084278] Lustre: Skipped 1 previous similar message [ 538.136582] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990be0621880 x1852870019348480/t25769803781(25769803781) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767035046 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'touch.0' uid:0 gid:0 projid:0 [ 539.537915] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 540.176976] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 544.129916] Lustre: DEBUG MARKER: == replay-single test 2c: setstripe replay =============== 14:03:55 (1767035035) [ 546.955027] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 552.418189] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 567.777065] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 567.785661] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b4ebb to 0xe79bd7b01d7b53e6 [ 567.790196] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 567.793653] Lustre: Skipped 1 previous similar message [ 568.339140] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990be0622680 x1852870019357952/t30064771076(30064771076) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 536/608 e 0 to 0 dl 1767035076 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'lfs.0' uid:0 gid:0 projid:0 [ 569.850639] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 570.570251] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 574.646400] Lustre: DEBUG MARKER: == replay-single test 2d: setdirstripe replay ============ 14:04:26 (1767035066) [ 577.978855] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 583.138728] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 598.498454] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 598.506504] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b53e6 to 0xe79bd7b01d7b58f5 [ 600.089320] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 600.093498] Lustre: Skipped 2 previous similar messages [ 601.563625] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 602.225596] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 606.127337] Lustre: DEBUG MARKER: == replay-single test 2e: O_CREAT|O_EXCL create replay === 14:04:57 (1767035097) [ 610.445352] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 622.047155] Lustre: 23047:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035098/real 1767035098] req@ffff990be06d3100 x1852870019375744/t0(0) o35->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:23/10 lens 392/624 e 0 to 1 dl 1767035114 ref 2 fl Rpc:XQr/600/ffffffff rc 0/-1 job:'openfile.0' uid:0 gid:0 projid:0 [ 629.215214] Lustre: 2404:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035105/real 1767035105] req@ffff990bd8a53800 x1852870019377920/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035121 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 629.219702] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 629.234206] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b58f5 to 0xe79bd7b01d7b5dcc [ 632.692377] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 633.353643] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 637.479280] Lustre: DEBUG MARKER: == replay-single test 3a: replay failed open(O_DIRECTORY) ========================================================== 14:05:28 (1767035128) [ 640.793930] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 644.578249] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 644.584353] Lustre: Skipped 1 previous similar message [ 664.094145] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 664.839805] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 668.849436] Lustre: DEBUG MARKER: == replay-single test 3b: replay failed open -ENOMEM ===== 14:06:00 (1767035160) [ 671.914608] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 690.660531] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 690.666236] LustreError: Skipped 1 previous similar message [ 690.672891] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b6295 to 0xe79bd7b01d7b66cb [ 690.677262] Lustre: Skipped 1 previous similar message [ 690.680066] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 690.684743] Lustre: Skipped 4 previous similar messages [ 695.812153] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 696.502773] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 700.342188] Lustre: DEBUG MARKER: == replay-single test 3c: replay failed open -ENOMEM ===== 14:06:31 (1767035191) [ 703.343344] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 726.388144] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 727.047176] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 730.776856] Lustre: DEBUG MARKER: == replay-single test 4a: |x| 10 open(O_CREAT)s ========== 14:07:02 (1767035222) [ 733.684347] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 736.738047] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 736.743790] Lustre: Skipped 2 previous similar messages [ 752.096545] Lustre: 2406:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035228/real 1767035228] req@ffff990bc37f5180 x1852870019419392/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035244 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 754.710108] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990be06d0380 x1852870019411968/t55834574851(55834574851) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767035262 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'bash.0' uid:0 gid:0 projid:0 [ 756.185578] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 756.806668] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 761.122240] Lustre: DEBUG MARKER: == replay-single test 4b: |x| rm 10 files ================ 14:07:32 (1767035252) [ 764.793943] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 782.818287] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 782.823304] LustreError: Skipped 2 previous similar messages [ 782.827984] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7b730b to 0xe79bd7b01d7b7e48 [ 782.831819] Lustre: Skipped 2 previous similar messages [ 787.894222] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 788.619188] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 792.833688] Lustre: DEBUG MARKER: == replay-single test 5: |x| 220 open(O_CREAT) =========== 14:08:04 (1767035284) [ 796.266623] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 821.269492] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990be0622a00 x1852870019461248/t64424509443(64424509443) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767035329 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'bash.0' uid:0 gid:0 projid:0 [ 821.279381] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 9 previous similar messages [ 822.551909] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 822.558344] Lustre: Skipped 8 previous similar messages [ 823.938908] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 824.593311] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 836.420688] Lustre: DEBUG MARKER: == replay-single test 6a: mkdir + contained create ======= 14:08:47 (1767035327) [ 839.647470] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 862.726756] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 863.449931] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 869.310837] Lustre: DEBUG MARKER: == replay-single test 6b: |X| rmdir ====================== 14:09:20 (1767035360) [ 872.353300] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 874.977506] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 874.984588] Lustre: Skipped 3 previous similar messages [ 894.885947] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 895.544474] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 899.583185] Lustre: DEBUG MARKER: == replay-single test 7: mkdir |X| contained create ====== 14:09:51 (1767035391) [ 902.607945] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 921.055136] Lustre: 2403:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035397/real 1767035397] req@ffff990bc5d50700 x1852870019949568/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035413 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 921.058292] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 921.072276] LustreError: Skipped 3 previous similar messages [ 921.075778] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7c1e37 to 0xe79bd7b01d7c233f [ 921.079133] Lustre: Skipped 3 previous similar messages [ 924.978319] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 925.607028] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 929.487225] Lustre: DEBUG MARKER: == replay-single test 8: creat open |X| close ============ 14:10:21 (1767035421) [ 932.436319] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 953.359831] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc51d4380 x1852870019960320/t81604378634(81604378634) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 664/608 e 0 to 0 dl 1767035461 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'multiop.0' uid:0 gid:0 projid:0 [ 953.367051] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 219 previous similar messages [ 954.702674] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 955.321799] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 959.084975] Lustre: DEBUG MARKER: == replay-single test 9: |X| create (same inum/gen) ====== 14:10:50 (1767035450) [ 961.947929] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 984.384643] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 985.007816] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 988.788236] Lustre: DEBUG MARKER: == replay-single test 10: create |X| rename unlink ======= 14:11:20 (1767035480) [ 991.592571] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1008.095468] Lustre: 2406:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035484/real 1767035484] req@ffff990bc6ebfb80 x1852870019978368/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035500 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1013.662823] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1014.331207] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1018.307181] Lustre: DEBUG MARKER: == replay-single test 11: create open write rename |X| create-old-name read ========================================================== 14:11:49 (1767035509) [ 1021.309969] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1042.449256] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc51d5f80 x1852870019989632/t94489280522(94489280522) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767035550 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'bash.0' uid:0 gid:0 projid:0 [ 1043.827380] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1044.483213] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1048.233155] Lustre: DEBUG MARKER: == replay-single test 12: open, unlink |X| close ========= 14:12:19 (1767035539) [ 1051.041959] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1073.573348] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1074.217922] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1078.053479] Lustre: DEBUG MARKER: == replay-single test 13: open chmod 0 |x| write close === 14:12:49 (1767035569) [ 1080.903807] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1099.999257] Lustre: 2403:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035576/real 1767035576] req@ffff990bc5d50a80 x1852870020012544/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035592 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1100.015425] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 1100.018854] Lustre: Skipped 16 previous similar messages [ 1100.036517] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc51d4e00 x1852870019990400/t94489280524(94489280524) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 576/608 e 0 to 0 dl 1767035608 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'grep.0' uid:0 gid:0 projid:0 [ 1100.045220] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 3 previous similar messages [ 1103.216195] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1103.820499] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1107.569671] Lustre: DEBUG MARKER: == replay-single test 14: open(O_CREAT), unlink |X| close ========================================================== 14:13:19 (1767035599) [ 1110.362190] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1132.400877] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1133.013688] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1136.664706] Lustre: DEBUG MARKER: == replay-single test 15: open(O_CREAT), unlink |X| touch new, close ========================================================== 14:13:48 (1767035628) [ 1139.362743] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1141.217472] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1141.223255] Lustre: Skipped 8 previous similar messages [ 1160.890137] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1161.451514] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1164.918899] Lustre: DEBUG MARKER: == replay-single test 16: |X| open(O_CREAT), unlink, touch new, unlink new ========================================================== 14:14:16 (1767035656) [ 1167.389286] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1187.297680] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 1187.301633] LustreError: Skipped 8 previous similar messages [ 1187.305520] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7c4ec7 to 0xe79bd7b01d7c543f [ 1187.309396] Lustre: Skipped 8 previous similar messages [ 1187.310813] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc51d4e00 x1852870019990400/t94489280524(94489280524) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 576/608 e 0 to 0 dl 1767035695 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'grep.0' uid:0 gid:0 projid:0 [ 1187.318473] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 6 previous similar messages [ 1189.006344] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1189.561563] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1193.140742] Lustre: DEBUG MARKER: == replay-single test 17: |X| open(O_CREAT), |replay| close ========================================================== 14:14:44 (1767035684) [ 1195.795193] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1217.914190] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1218.560256] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1222.347258] Lustre: DEBUG MARKER: == replay-single test 18: open(O_CREAT), unlink, touch new, close, touch, unlink ========================================================== 14:15:13 (1767035713) [ 1224.896422] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1246.504650] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1247.109642] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1250.900422] Lustre: DEBUG MARKER: == replay-single test 19: mcreate, open, write, rename === 14:15:42 (1767035742) [ 1253.835927] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1276.202603] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1276.792258] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1280.710697] Lustre: DEBUG MARKER: == replay-single test 20a: |X| open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 14:16:12 (1767035772) [ 1283.455192] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1299.936123] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035776/real 1767035776] req@ffff990bc51d6a00 x1852870020087552/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035792 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1304.886401] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1305.537228] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1309.331783] Lustre: DEBUG MARKER: == replay-single test 20b: write, unlink, eviction, replay (test mds_cleanup_orphans) ========================================================== 14:16:40 (1767035800) [ 1311.967693] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_statfs to node 192.168.203.127@tcp failed: rc = -107 [ 1311.973150] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1311.979420] LustreError: 57066:0:(file.c:249:ll_close_inode_openhandle()) lustre-clilmv-ffff990bd119f800: inode [0x200001b71:0x118:0x0] mdc close failed: rc = -108 [ 1311.979499] LustreError: 57009:0:(vvp_io.c:1910:vvp_io_init()) lustre: refresh file layout [0x200001b71:0x132:0x0] error -108. [ 1333.989169] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1334.609508] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1339.549249] Lustre: DEBUG MARKER: before 3156, after 3156 [ 1341.909175] Lustre: DEBUG MARKER: == replay-single test 20c: check that client eviction does not affect file content ========================================================== 14:17:13 (1767035833) [ 1343.624311] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_statfs to node 192.168.203.127@tcp failed: rc = -107 [ 1343.631987] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1347.535381] Lustre: DEBUG MARKER: == replay-single test 21: |X| open(O_CREAT), unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 14:17:19 (1767035839) [ 1350.190357] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1370.638133] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc5d50000 x1852870020111744/t141733920773(141733920773) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767035878 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'multiop.0' uid:0 gid:0 projid:0 [ 1370.645525] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 9 previous similar messages [ 1371.946665] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1372.563617] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1376.072343] Lustre: DEBUG MARKER: == replay-single test 22: open(O_CREAT), |X| unlink, replay, close (test mds_cleanup_orphans) ========================================================== 14:17:47 (1767035867) [ 1378.737638] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1400.559174] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1401.129709] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1404.494770] Lustre: DEBUG MARKER: == replay-single test 23: open(O_CREAT), |X| unlink touch new, replay, close (test mds_cleanup_orphans) ========================================================== 14:18:16 (1767035896) [ 1407.099443] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1428.690714] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1429.247550] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1432.847908] Lustre: DEBUG MARKER: == replay-single test 24: open(O_CREAT), replay, unlink, close (test mds_cleanup_orphans) ========================================================== 14:18:44 (1767035924) [ 1435.625573] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1457.361511] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1457.921198] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1461.414839] Lustre: DEBUG MARKER: == replay-single test 25: open(O_CREAT), unlink, replay, close (test mds_cleanup_orphans) ========================================================== 14:19:13 (1767035953) [ 1464.206985] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1484.255135] Lustre: 2404:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767035960/real 1767035960] req@ffff990bc5c43800 x1852870020155264/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767035976 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1484.264314] Lustre: 2404:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1485.965092] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1486.510689] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1489.920137] Lustre: DEBUG MARKER: == replay-single test 26: |X| open(O_CREAT), unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 14:19:41 (1767035981) [ 1492.370652] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1513.568877] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1514.074442] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1517.375449] Lustre: DEBUG MARKER: == replay-single test 27: |X| open(O_CREAT), unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 14:20:09 (1767036009) [ 1519.790457] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1541.298657] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1541.867216] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1545.236093] Lustre: DEBUG MARKER: == replay-single test 28: open(O_CREAT), |X| unlink two, close one, replay, close one (test mds_cleanup_orphans) ========================================================== 14:20:36 (1767036036) [ 1547.807148] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1569.375669] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1569.908348] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1573.378780] Lustre: DEBUG MARKER: == replay-single test 29: open(O_CREAT), |X| unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 14:21:04 (1767036064) [ 1576.082180] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1577.952568] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation ost_set_info to node 192.168.203.127@tcp failed: rc = -107 [ 1597.614613] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1598.160237] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1601.773198] Lustre: DEBUG MARKER: == replay-single test 30: open(O_CREAT) two, unlink two, replay, close two (test mds_cleanup_orphans) ========================================================== 14:21:33 (1767036093) [ 1604.756932] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1622.498752] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 1622.502767] Lustre: Skipped 37 previous similar messages [ 1626.129939] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1626.662607] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1630.048158] Lustre: DEBUG MARKER: == replay-single test 31: open(O_CREAT) two, unlink one, |X| unlink one, close two (test mds_cleanup_orphans) ========================================================== 14:22:01 (1767036121) [ 1632.534464] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1648.107378] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc5d53100 x1852870020218624/t184683593733(184683593733) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767036156 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'multiop.0' uid:0 gid:0 projid:0 [ 1648.115910] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 17 previous similar messages [ 1653.972555] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1654.568112] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1658.120179] Lustre: DEBUG MARKER: == replay-single test 32: close() notices client eviction; close() after client eviction ========================================================== 14:22:29 (1767036149) [ 1659.807599] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_statfs to node 192.168.203.127@tcp failed: rc = -107 [ 1659.811455] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1659.816457] Lustre: Skipped 19 previous similar messages [ 1659.819694] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1663.361754] Lustre: DEBUG MARKER: == replay-single test 33a: fid seq shouldn't be reused after abort recovery ========================================================== 14:22:34 (1767036154) [ 1665.800631] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1673.698709] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1684.170017] Lustre: DEBUG MARKER: == replay-single test 33b: test fid seq allocation ======= 14:22:55 (1767036175) [ 1686.718930] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1694.179103] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1704.887411] Lustre: DEBUG MARKER: == replay-single test 34: abort recovery before client does replay (test mds_cleanup_orphans) ========================================================== 14:23:16 (1767036196) [ 1707.433718] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1714.656634] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 1714.658175] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1714.660302] LustreError: Skipped 18 previous similar messages [ 1714.665691] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d7cc0db to 0xe79bd7b01d7cc9cc [ 1714.668736] Lustre: Skipped 18 previous similar messages [ 1724.726632] Lustre: DEBUG MARKER: == replay-single test 35: test recovery from llog for unlink op ========================================================== 14:23:36 (1767036216) [ 1735.138770] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1735.142557] LustreError: 80117:0:(file.c:6123:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000007:0x1:0x0] error: rc = -5 [ 1744.492083] Lustre: DEBUG MARKER: SKIP: replay-single test_36 skipping ALWAYS excluded test 36 [ 1744.987665] Lustre: DEBUG MARKER: == replay-single test 37: abort recovery before client does replay (test mds_cleanup_orphans for directories) ========================================================== 14:23:56 (1767036236) [ 1747.383586] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1755.618088] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 1765.618883] Lustre: DEBUG MARKER: == replay-single test 38: test recovery from unlink llog (test llog_gen_rec) ========================================================== 14:24:17 (1767036257) [ 1774.921617] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1796.203184] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1796.725650] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1804.898907] Lustre: DEBUG MARKER: == replay-single test 39: test recovery from unlink llog (test llog_gen_rec) ========================================================== 14:24:56 (1767036296) [ 1811.723374] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1835.993758] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1836.561430] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1844.737316] Lustre: DEBUG MARKER: == replay-single test 41: read from a valid osc while other oscs are invalid ========================================================== 14:25:36 (1767036336) [ 1847.774469] Lustre: DEBUG MARKER: == replay-single test 42: recovery after ost failure ===== 14:25:39 (1767036339) [ 1854.632281] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 1920.361860] Lustre: DEBUG MARKER: == replay-single test 43: mds osc import failure during recovery; don't LBUG ========================================================== 14:26:51 (1767036411) [ 1923.238925] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 1939.935145] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767036416/real 1767036416] req@ffff990bd8085500 x1852870022897920/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767036432 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1939.945734] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1945.389420] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1946.000668] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1959.747666] Lustre: DEBUG MARKER: == replay-single test 44a: race in target handle connect ========================================================== 14:27:31 (1767036451) [ 2025.315967] Lustre: DEBUG MARKER: == replay-single test 44b: race in target handle connect ========================================================== 14:28:36 (1767036516) [ 2046.437579] LustreError: 91007:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2067.428467] LustreError: 91029:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2088.419654] LustreError: 91051:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2109.412475] LustreError: 91073:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2130.403340] LustreError: 91095:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2151.140483] LustreError: 91117:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2172.388928] LustreError: 91139:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2214.373130] LustreError: 91183:0:(lmv_obd.c:1435:lmv_statfs()) lustre-MDT0000-mdc-ffff990bd119f800: can't stat MDS #0: rc = -114 [ 2214.376063] LustreError: 91183:0:(lmv_obd.c:1435:lmv_statfs()) Skipped 1 previous similar message [ 2237.573846] Lustre: DEBUG MARKER: == replay-single test 44c: race in target handle connect ========================================================== 14:32:09 (1767036729) [ 2237.923734] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 2237.928277] Lustre: Skipped 30 previous similar messages [ 2240.156515] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2248.163557] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2275.850995] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2276.369765] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2279.695637] Lustre: DEBUG MARKER: == replay-single test 45: Handle failed close ============ 14:32:51 (1767036771) [ 2279.731901] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2279.738383] Lustre: Skipped 22 previous similar messages [ 2279.761182] Lustre: setting import lustre-MDT0000_UUID INACTIVE by administrator request [ 2279.765939] LustreError: 93728:0:(file.c:249:ll_close_inode_openhandle()) lustre-clilmv-ffff990bd119f800: inode [0x20001a9e1:0x1:0x0] mdc close failed: rc = -108 [ 2279.774916] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 2282.657883] Lustre: DEBUG MARKER: == replay-single test 46: Don't leak file handle after open resend (3325) ========================================================== 14:32:54 (1767036774) [ 2314.721251] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 2314.726454] LustreError: Skipped 7 previous similar messages [ 2314.729866] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d810211 to 0xe79bd7b01d8105f3 [ 2314.732361] Lustre: Skipped 7 previous similar messages [ 2320.068578] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2320.667259] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2324.719307] Lustre: DEBUG MARKER: == replay-single test 47: MDS->OSC failure during precreate cleanup (2824) ========================================================== 14:33:36 (1767036816) [ 2343.782465] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2344.332042] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 2409.556476] Lustre: DEBUG MARKER: == replay-single test 48: MDS->OSC failure during precreate cleanup (2824) ========================================================== 14:35:01 (1767036901) [ 2412.134309] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2432.525680] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc7a1b480 x1852870023051904/t236223201383(236223201383) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767036984 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'createmany.0' uid:0 gid:0 projid:0 [ 2432.535813] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 1 previous similar message [ 2495.163619] Lustre: DEBUG MARKER: == replay-single test 50: Double OSC recovery, don't LASSERT (3812) ========================================================== 14:36:26 (1767036986) [ 2503.263258] Lustre: DEBUG MARKER: == replay-single test 52: time out lock replay (3764) ==== 14:36:34 (1767036994) [ 2579.423144] Lustre: 2402:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767037011/real 1767037011] req@ffff990bd81b0e00 x1852870023110144/t0(0) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 328/344 e 0 to 1 dl 1767037071 ref 1 fl Rpc:XQr/240/ffffffff rc 0/-1 job:'ldlm_lock_repla.0' uid:0 gid:0 projid:4294967295 [ 2579.435277] Lustre: 2402:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 2580.840763] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2581.403619] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2585.134599] Lustre: DEBUG MARKER: == replay-single test 53a: |X| close request while two MDC requests in flight ========================================================== 14:37:56 (1767037076) [ 2589.347880] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2610.922208] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2611.475264] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2614.983668] Lustre: DEBUG MARKER: == replay-single test 53b: |X| open request while two MDC requests in flight ========================================================== 14:38:26 (1767037106) [ 2619.176102] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2640.486692] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2641.020397] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2644.517333] Lustre: DEBUG MARKER: == replay-single test 53c: |X| open request and close request while two MDC requests in flight ========================================================== 14:38:56 (1767037136) [ 2648.587161] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2673.000512] Lustre: DEBUG MARKER: == replay-single test 53d: close reply while two MDC requests in flight ========================================================== 14:39:24 (1767037164) [ 2694.877115] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2695.466534] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2699.035306] Lustre: DEBUG MARKER: == replay-single test 53e: |X| open reply while two MDC requests in flight ========================================================== 14:39:50 (1767037190) [ 2703.115593] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2724.487486] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2725.003565] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2728.381988] Lustre: DEBUG MARKER: == replay-single test 53f: |X| open reply and close reply while two MDC requests in flight ========================================================== 14:40:20 (1767037220) [ 2732.449577] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2756.959955] Lustre: DEBUG MARKER: == replay-single test 53g: |X| drop open reply and close request while close and open are both in flight ========================================================== 14:40:48 (1767037248) [ 2761.291662] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2785.437355] Lustre: DEBUG MARKER: == replay-single test 53h: open request and close reply while two MDC requests in flight ========================================================== 14:41:17 (1767037277) [ 2790.573888] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2815.492930] Lustre: DEBUG MARKER: == replay-single test 55: let MDS_CHECK_RESENT return the original return code instead of 0 ========================================================== 14:41:47 (1767037307) [ 2875.364886] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 2875.367407] Lustre: Skipped 29 previous similar messages [ 2877.636940] Lustre: DEBUG MARKER: == replay-single test 56: don't replay a symlink open request (3440) ========================================================== 14:42:49 (1767037369) [ 2880.143808] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2885.600845] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2885.604943] Lustre: Skipped 15 previous similar messages [ 2901.591614] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2902.103323] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2915.673288] Lustre: DEBUG MARKER: == replay-single test 57: test recovery from llog for setattr op ========================================================== 14:43:27 (1767037407) [ 2918.558514] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2936.800942] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 2936.805266] LustreError: Skipped 11 previous similar messages [ 2936.808792] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d816530 to 0xe79bd7b01d816a9a [ 2936.811235] Lustre: Skipped 11 previous similar messages [ 2940.064257] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2940.619550] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2948.082217] Lustre: DEBUG MARKER: == replay-single test 58a: test recovery from llog for setattr op (test llog_gen_rec) ========================================================== 14:43:59 (1767037439) [ 2957.407707] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 2978.982458] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2979.561294] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2993.144679] Lustre: DEBUG MARKER: == replay-single test 58b: test replay of setxattr op ==== 14:44:44 (1767037484) [ 2994.247091] Lustre: Mounted lustre-client [ 2997.007257] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3018.383590] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3018.898746] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3020.537113] LustreError: 116383:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bc6d36800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 3020.540044] LustreError: 116383:0:(lov_obd.c:783:lov_cleanup()) Skipped 1 previous similar message [ 3020.542128] LustreError: 116383:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3020.544483] LustreError: 116383:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 3020.562682] Lustre: Unmounted lustre-client [ 3021.666626] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount FULL mgc.*.mgs_server_uuid [ 3022.194635] Lustre: DEBUG MARKER: mgc.*.mgs_server_uuid in FULL state after 0 sec [ 3024.305577] Lustre: DEBUG MARKER: == replay-single test 58c: resend/reconstruct setxattr op ========================================================== 14:45:15 (1767037515) [ 3029.749178] Lustre: Mounted lustre-client [ 3152.676233] LustreError: 117511:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bc84d4000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 3152.679142] LustreError: 117511:0:(lov_obd.c:783:lov_cleanup()) Skipped 1 previous similar message [ 3152.681640] LustreError: 117511:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3152.683590] LustreError: 117511:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 3152.700428] Lustre: Unmounted lustre-client [ 3154.847749] Lustre: DEBUG MARKER: SKIP: replay-single test_59 skipping ALWAYS excluded test 59 [ 3155.357380] Lustre: DEBUG MARKER: == replay-single test 60: test llog post recovery init vs llog unlink ========================================================== 14:47:27 (1767037647) [ 3159.409531] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3181.416971] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3181.929754] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3185.639907] Lustre: DEBUG MARKER: == replay-single test 61a: test race llog recovery vs llog cleanup ========================================================== 14:47:57 (1767037677) [ 3191.169565] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 3239.813058] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3240.350685] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 3274.374717] Lustre: DEBUG MARKER: == replay-single test 61b: test race mds llog sync vs llog cleanup ========================================================== 14:49:25 (1767037765) [ 3321.969986] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3322.553110] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3326.199782] Lustre: DEBUG MARKER: == replay-single test 61c: test race mds llog sync vs llog cleanup ========================================================== 14:50:17 (1767037817) [ 3355.716135] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3356.293410] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 3360.129866] Lustre: DEBUG MARKER: == replay-single test 61d: error in llog_setup should cleanup the llog context correctly ========================================================== 14:50:51 (1767037851) [ 3372.479970] Lustre: DEBUG MARKER: == replay-single test 62: don't mis-drop resent replay === 14:51:04 (1767037864) [ 3376.350105] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3452.895129] Lustre: 2402:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767037884/real 1767037884] req@ffff990bc5775500 x1852870026847872/t313532612610(313532612610) o36->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 528/448 e 0 to 1 dl 1767037944 ref 2 fl Rpc:XQr/204/ffffffff rc 0/-1 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 3452.902117] Lustre: 2402:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 12 previous similar messages [ 3452.904041] LustreError: 2402:0:(client.c:3367:ptlrpc_replay_interpret()) @@@ request replay timed out req@ffff990bc5775500 x1852870026847872/t313532612610(313532612610) o36->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 528/448 e 0 to 1 dl 1767037944 ref 2 fl Interpret:EXQU/204/ffffffff rc -110/-1 job:'mcreate.0' uid:0 gid:0 projid:4294967295 [ 3452.932645] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc6180000 x1852870026850176/t313532612612(313532612612) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 592/608 e 0 to 0 dl 1767038005 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'createmany.0' uid:0 gid:0 projid:0 [ 3452.939234] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 19 previous similar messages [ 3454.315563] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3454.868936] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3458.510141] Lustre: DEBUG MARKER: == replay-single test 65a: AT: verify early replies ====== 14:52:30 (1767037950) [ 3505.062124] Lustre: DEBUG MARKER: == replay-single test 65b: AT: verify early replies on packed reply / bulk ========================================================== 14:53:16 (1767037996) [ 3543.783566] Lustre: DEBUG MARKER: == replay-single test 66a: AT: verify MDT service time adjusts with no early replies ========================================================== 14:53:55 (1767038035) [ 3594.960250] Lustre: DEBUG MARKER: == replay-single test 66b: AT: verify net latency adjusts ========================================================== 14:54:46 (1767038086) [ 3617.988308] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c sleeping for 10000ms [ 3628.079144] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c awake [ 3628.085924] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c sleeping for 10000ms [ 3638.175144] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c awake [ 3638.179907] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c sleeping for 10000ms [ 3648.271080] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c awake [ 3648.276212] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c sleeping for 10000ms [ 3658.367126] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c awake [ 3658.374438] LustreError: 2403:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c sleeping for 10000ms [ 3668.463216] LustreError: 2403:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c awake [ 3668.471113] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c sleeping for 10000ms [ 3678.567129] LustreError: 130246:0:(client.c:1679:after_reply()) cfs_fail_timeout id 50c awake [ 3681.317922] Lustre: DEBUG MARKER: == replay-single test 67a: AT: verify slow request processing doesn't induce reconnects ========================================================== 14:56:12 (1767038172) [ 3748.663614] Lustre: DEBUG MARKER: == replay-single test 67b: AT: verify instant slowdown doesn't induce reconnects ========================================================== 14:57:20 (1767038240) [ 3772.755931] Lustre: DEBUG MARKER: phase 2 [ 3775.557715] Lustre: DEBUG MARKER: == replay-single test 68: AT: verify slowing locks ======= 14:57:47 (1767038267) [ 3799.456596] LustreError: 32948:0:(ldlm_request.c:1402:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 sleeping for 19000ms [ 3818.495127] LustreError: 32948:0:(ldlm_request.c:1402:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 awake [ 3847.131604] Lustre: DEBUG MARKER: == replay-single test 70a: check multi client t-f ======== 14:58:58 (1767038338) [ 3847.846729] Lustre: DEBUG MARKER: SKIP: replay-single test_70a Need two or more clients, have 1 [ 3848.727584] Lustre: DEBUG MARKER: == replay-single test 70b: dbench 2mdts recovery; 1 clients ========================================================== 14:59:00 (1767038340) [ 3850.876351] Lustre: DEBUG MARKER: Started rundbench load pid=133570 ... [ 3855.708837] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3857.418702] Lustre: DEBUG MARKER: test_70b fail mds1 1 times [ 3858.329840] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation ldlm_enqueue to node 192.168.203.127@tcp failed: rc = -19 [ 3858.335107] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 3858.342462] Lustre: Skipped 14 previous similar messages [ 3878.882450] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 3878.891870] LustreError: Skipped 7 previous similar messages [ 3878.897854] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d86bd39 to 0xe79bd7b01d876fce [ 3878.903690] Lustre: Skipped 7 previous similar messages [ 3878.907281] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 3878.911929] Lustre: Skipped 22 previous similar messages [ 3882.008396] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3882.654748] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3888.310550] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 3889.877692] Lustre: DEBUG MARKER: test_70b fail mds2 2 times [ 3913.459239] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 3914.263872] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3920.512939] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 3922.174429] Lustre: DEBUG MARKER: test_70b fail mds1 3 times [ 3922.948097] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_close to node 192.168.203.127@tcp failed: rc = -107 [ 3946.347395] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3947.178806] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3953.215201] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 3955.027723] Lustre: DEBUG MARKER: test_70b fail mds2 4 times [ 3978.749100] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 3979.490277] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 3997.286507] Lustre: DEBUG MARKER: == replay-single test 70c: tar 2mdts recovery ============ 15:01:28 (1767038488) [ 4120.667378] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 4131.405483] Lustre: DEBUG MARKER: test_70c fail mds2 1 times [ 4132.217524] LustreError: lustre-MDT0001-mdc-ffff990bd119f800: operation ldlm_cancel to node 192.168.203.127@tcp failed: rc = -19 [ 4159.007043] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc7b30a80 x1852870042858240/t12884913282(12884913282) o101->lustre-MDT0001-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 584/608 e 0 to 0 dl 1767038667 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'tar.0' uid:0 gid:0 projid:0 [ 4159.020410] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 131 previous similar messages [ 4163.460604] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 4164.207345] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4289.168408] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 4299.638696] Lustre: DEBUG MARKER: test_70c fail mds2 2 times [ 4325.294983] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 4325.957579] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4367.076232] Lustre: DEBUG MARKER: == replay-single test 70d: mkdir/rmdir striped dir 2mdts recovery ========================================================== 15:07:38 (1767038858) [ 4491.156722] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 4501.957062] Lustre: DEBUG MARKER: test_70d fail mds1 1 times [ 4503.127431] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_readpage to node 192.168.203.127@tcp failed: rc = -107 [ 4503.131632] LustreError: Skipped 1 previous similar message [ 4503.133666] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4503.139749] Lustre: Skipped 5 previous similar messages [ 4521.951200] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767038998/real 1767038998] req@ffff990bd16a5500 x1852870067212288/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767039014 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4521.965925] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 4521.972067] LustreError: Skipped 1 previous similar message [ 4521.976517] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01d8a504f to 0xe79bd7b01db37932 [ 4521.982328] Lustre: Skipped 1 previous similar message [ 4521.985601] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 4521.993155] Lustre: Skipped 7 previous similar messages [ 4527.476829] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4528.201710] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4653.660860] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 4664.387261] Lustre: DEBUG MARKER: test_70d fail mds1 2 times [ 4665.624274] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_reint to node 192.168.203.127@tcp failed: rc = -19 [ 4694.908986] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4695.642468] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4700.311490] Lustre: DEBUG MARKER: == replay-single test 70e: rename cross-MDT with random fails ========================================================== 15:13:11 (1767039191) [ 4824.603270] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 4835.320705] Lustre: DEBUG MARKER: test_70e fail mds1 1 times [ 4857.877272] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bc355ed80 x1852870078596992/t335007460734(335007460734) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 576/608 e 0 to 0 dl 1767039365 ref 2 fl Interpret:RQU/604/0 rc 301/301 job:'touch.0' uid:0 gid:0 projid:0 [ 4857.890517] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 530 previous similar messages [ 4863.306646] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 4863.942900] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 4989.448584] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5000.057563] Lustre: DEBUG MARKER: test_70e fail mds2 2 times [ 5023.561673] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5024.148945] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5028.231779] Lustre: DEBUG MARKER: == replay-single test 70f: OSS O_DIRECT recovery with 1 clients ========================================================== 15:18:39 (1767039519) [ 5034.902100] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 5036.666882] Lustre: DEBUG MARKER: test_70f failing OST 1 times [ 5059.754400] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5060.324930] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5070.251942] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 5072.020923] Lustre: DEBUG MARKER: test_70f failing OST 2 times [ 5094.795265] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 5095.364495] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 5101.802760] Lustre: DEBUG MARKER: == replay-single test 71a: mkdir/rmdir striped dir with 2 mdts recovery ========================================================== 15:19:53 (1767039593) [ 5225.406301] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5229.101490] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5239.775642] Lustre: DEBUG MARKER: fail mds1 mds2 1 times [ 5240.923376] LustreError: lustre-MDT0000-mdc-ffff990bd119f800: operation mds_reint to node 192.168.203.127@tcp failed: rc = -19 [ 5240.928293] LustreError: Skipped 1 previous similar message [ 5240.930793] Lustre: lustre-MDT0000-mdc-ffff990bd119f800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5240.938673] Lustre: Skipped 5 previous similar messages [ 5259.231181] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767039735/real 1767039735] req@ffff990bc6839f80 x1852870090090368/t0(0) o400->lustre-MDT0001-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 224/224 e 0 to 1 dl 1767039751 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5259.245329] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 5259.249536] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 5259.255283] LustreError: Skipped 2 previous similar messages [ 5259.260902] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01dc5f491 to 0xe79bd7b01ddab3f4 [ 5259.266170] Lustre: Skipped 2 previous similar messages [ 5259.269422] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 5259.273842] Lustre: Skipped 7 previous similar messages [ 5284.218262] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5284.929221] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5285.624258] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5289.858081] Lustre: DEBUG MARKER: == replay-single test 73a: open(O_CREAT), unlink, replay, reconnect before open replay, close ========================================================== 15:23:01 (1767039781) [ 5293.048291] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5330.911133] LustreError: 2402:0:(client.c:3367:ptlrpc_replay_interpret()) @@@ request replay timed out req@ffff990bd1702680 x1852870085549312/t339302430669(339302430669) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 520/664 e 0 to 1 dl 1767039822 ref 2 fl Interpret:EXPQU/604/ffffffff rc -110/-1 job:'lfs.0' uid:0 gid:0 projid:0 [ 5332.065815] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5332.513813] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5335.586699] Lustre: DEBUG MARKER: == replay-single test 73b: open(O_CREAT), unlink, replay, reconnect at open_replay reply, close ========================================================== 15:23:47 (1767039827) [ 5337.734768] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5371.871111] LustreError: 2402:0:(client.c:3367:ptlrpc_replay_interpret()) @@@ request replay timed out req@ffff990bd1702680 x1852870085549312/t339302430669(339302430669) o101->lustre-MDT0000-mdc-ffff990bd119f800@192.168.203.127@tcp:12/10 lens 520/664 e 0 to 1 dl 1767039863 ref 2 fl Interpret:EXPQU/604/ffffffff rc -110/-1 job:'lfs.0' uid:0 gid:0 projid:0 [ 5373.132684] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5373.647245] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5377.136605] Lustre: DEBUG MARKER: == replay-single test 74: Ensure applications don't fail waiting for OST recovery ========================================================== 15:24:28 (1767039868) [ 5377.681018] LustreError: 200717:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bd119f800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 5377.684920] LustreError: 200717:0:(lov_obd.c:783:lov_cleanup()) Skipped 1 previous similar message [ 5377.689656] LustreError: 200717:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [ 5377.692124] LustreError: 200717:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 5377.720592] Lustre: Unmounted lustre-client [ 5400.564696] Lustre: Mounted lustre-client [ 5409.539155] Lustre: DEBUG MARKER: == replay-single test 80a: DNE: create remote dir, drop update rep from MDT0, fail MDT0 ========================================================== 15:25:01 (1767039901) [ 5412.596855] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5434.613459] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5435.326518] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5439.212896] Lustre: DEBUG MARKER: == replay-single test 80b: DNE: create remote dir, drop update rep from MDT0, fail MDT1 ========================================================== 15:25:30 (1767039930) [ 5442.030845] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5444.400736] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5471.387199] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5471.987741] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5475.710388] Lustre: DEBUG MARKER: == replay-single test 80c: DNE: create remote dir, drop update rep from MDT1, fail MDT[0,1] ========================================================== 15:26:07 (1767039967) [ 5478.654287] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5481.417655] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5501.980984] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990be0207100 x1852870090352640/t360777252896(360777252896) o101->lustre-MDT0000-mdc-ffff990bc6d36800@192.168.203.127@tcp:12/10 lens 520/664 e 0 to 0 dl 1767040010 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'lfs.0' uid:0 gid:0 projid:0 [ 5501.994499] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 267 previous similar messages [ 5503.102986] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5503.650814] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5528.159123] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5528.978785] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5533.726676] Lustre: DEBUG MARKER: == replay-single test 80d: DNE: create remote dir, drop update rep from MDT1, fail 2 MDTs ========================================================== 15:27:05 (1767040025) [ 5540.806660] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5544.437788] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5578.697778] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5579.355150] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5579.991928] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5584.622150] Lustre: DEBUG MARKER: == replay-single test 80e: DNE: create remote dir, drop MDT1 rep, fail MDT0 ========================================================== 15:27:56 (1767040076) [ 5591.308737] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5615.134886] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5615.904371] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5643.700551] Lustre: DEBUG MARKER: == replay-single test 80f: DNE: create remote dir, drop MDT1 rep, fail MDT1 ========================================================== 15:28:55 (1767040135) [ 5647.616631] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5670.657989] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5671.391260] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5675.577344] Lustre: DEBUG MARKER: == replay-single test 80g: DNE: create remote dir, drop MDT1 rep, fail MDT0, then MDT1 ========================================================== 15:29:27 (1767040167) [ 5681.651030] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5683.998978] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5707.101355] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5707.604513] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5731.408387] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5731.940063] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5735.445450] Lustre: DEBUG MARKER: == replay-single test 80h: DNE: create remote dir, drop MDT1 rep, fail 2 MDTs ========================================================== 15:30:27 (1767040227) [ 5742.197143] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5745.858824] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5779.775693] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5780.490945] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5781.079696] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5785.758208] Lustre: DEBUG MARKER: == replay-single test 81a: DNE: unlink remote dir, drop MDT0 update rep, fail MDT1 ========================================================== 15:31:17 (1767040277) [ 5790.009370] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5790.859095] LustreError: lustre-MDT0001-mdc-ffff990bc6d36800: operation mds_reint to node 192.168.203.127@tcp failed: rc = -19 [ 5790.863677] LustreError: Skipped 4 previous similar messages [ 5819.936768] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5820.675507] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5825.310994] Lustre: DEBUG MARKER: == replay-single test 81b: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0 ========================================================== 15:31:56 (1767040316) [ 5829.506273] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5853.323681] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5854.132449] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5858.626958] Lustre: DEBUG MARKER: == replay-single test 81c: DNE: unlink remote dir, drop MDT0 update reply, fail MDT0,MDT1 ========================================================== 15:32:30 (1767040350) [ 5862.589384] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5866.117286] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5871.074241] Lustre: lustre-MDT0000-mdc-ffff990bc6d36800: Connection to lustre-MDT0000 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5871.082526] Lustre: Skipped 19 previous similar messages [ 5886.433706] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 5886.440172] LustreError: Skipped 9 previous similar messages [ 5886.445465] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01ddbe13a to 0xe79bd7b01ddbe7a7 [ 5886.451031] Lustre: Skipped 9 previous similar messages [ 5886.454153] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 5886.458705] Lustre: Skipped 29 previous similar messages [ 5890.113724] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5890.905459] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5915.989386] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5916.597354] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5921.042975] Lustre: DEBUG MARKER: == replay-single test 81d: DNE: unlink remote dir, drop MDT0 update reply, fail 2 MDTs ========================================================== 15:33:32 (1767040412) [ 5925.103667] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5928.840455] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 5946.847171] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767040422/real 1767040422] req@ffff990bd1700a80 x1852870090609152/t0(0) o400->MGC192.168.203.127@tcp@192.168.203.127@tcp:26/25 lens 224/224 e 0 to 1 dl 1767040438 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5946.862184] Lustre: 2405:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 18 previous similar messages [ 5963.616654] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 5964.451565] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5965.185948] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 5969.441276] Lustre: DEBUG MARKER: == replay-single test 81e: DNE: unlink remote dir, drop MDT1 req reply, fail MDT0 ========================================================== 15:34:20 (1767040460) [ 5974.328879] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 5998.741260] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 5999.574129] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6003.829830] Lustre: DEBUG MARKER: == replay-single test 81f: DNE: unlink remote dir, drop MDT1 req reply, fail MDT1 ========================================================== 15:34:55 (1767040495) [ 6008.194058] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6032.442221] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6033.289201] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6037.856288] Lustre: DEBUG MARKER: == replay-single test 81g: DNE: unlink remote dir, drop req reply, fail M0, then M1 ========================================================== 15:35:29 (1767040529) [ 6042.264784] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6046.013946] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6070.523698] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6071.418280] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6097.125783] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6097.894261] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6102.719131] Lustre: DEBUG MARKER: == replay-single test 81h: DNE: unlink remote dir, drop request reply, fail 2 MDTs ========================================================== 15:36:34 (1767040594) [ 6107.039769] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6110.829277] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0001 [ 6147.445689] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid,mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 6148.291545] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6149.006143] Lustre: DEBUG MARKER: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6153.931299] Lustre: DEBUG MARKER: == replay-single test 84a: stale open during export disconnect ========================================================== 15:37:25 (1767040645) [ 6156.260989] LustreError: lustre-MDT0000-mdc-ffff990bc6d36800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 6159.632408] Lustre: DEBUG MARKER: == replay-single test 85a: check the cancellation of unused locks during recovery(IBITS) ========================================================== 15:37:31 (1767040651) [ 6181.876831] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff990bd08f1500 x1852870090680576/t408021893128(408021893128) o101->lustre-MDT0000-mdc-ffff990bc6d36800@192.168.203.127@tcp:12/10 lens 576/608 e 0 to 0 dl 1767040689 ref 2 fl Interpret:RPQU/604/0 rc 301/301 job:'grep.0' uid:0 gid:0 projid:0 [ 6181.893243] LustreError: 2402:0:(client.c:3418:ptlrpc_replay_interpret()) Skipped 3 previous similar messages [ 6184.317745] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6185.197714] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6190.041182] Lustre: DEBUG MARKER: == replay-single test 85b: check the cancellation of unused locks during recovery(EXTENT) ========================================================== 15:38:01 (1767040681) [ 6217.193497] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6218.070736] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6223.076294] Lustre: DEBUG MARKER: == replay-single test 86: umount server after clear nid_stats should not hit LBUG ========================================================== 15:38:34 (1767040714) [ 6223.620150] LustreError: 234935:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bc6d36800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6223.626671] LustreError: 234935:0:(lov_obd.c:783:lov_cleanup()) Skipped 1 previous similar message [ 6223.633579] LustreError: 234935:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [ 6223.637315] LustreError: 234935:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 6223.680228] Lustre: Unmounted lustre-client [ 6236.662751] Lustre: Mounted lustre-client [ 6240.058823] Lustre: DEBUG MARKER: == replay-single test 87a: write replay ================== 15:38:51 (1767040731) [ 6244.152548] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 6268.102645] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6269.009542] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6273.954652] Lustre: DEBUG MARKER: == replay-single test 87b: write replay with changed data (checksum resend) ========================================================== 15:39:25 (1767040765) [ 6277.989646] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 6302.737792] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6303.566839] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6308.288915] Lustre: DEBUG MARKER: == replay-single test 88: MDS should not assign same objid to different files ========================================================== 15:39:59 (1767040799) [ 6311.966827] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-OST0000 [ 6315.556813] Lustre: DEBUG MARKER: local REPLAY BARRIER on lustre-MDT0000 [ 6373.403272] Lustre: DEBUG MARKER: == replay-single test 89: no disk space leak on late ost connection ========================================================== 15:41:04 (1767040864) [ 6401.243933] LustreError: 240775:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bd1c07800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6401.250244] LustreError: 240775:0:(lov_obd.c:783:lov_cleanup()) Skipped 1 previous similar message [ 6401.257171] LustreError: 240775:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [ 6401.260904] LustreError: 240775:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 6401.305917] Lustre: Unmounted lustre-client [ 6407.817746] Lustre: Mounted lustre-client [ 6407.824962] LustreError: lustre-OST0000-osc-ffff990bd0a86000: operation ost_connect to node 192.168.203.127@tcp failed: rc = -16 [ 6407.827212] LustreError: Skipped 2 previous similar messages [ 6481.130930] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 69 sec [ 6485.662187] Lustre: DEBUG MARKER: free_before: 7646268 free_after: 7646268 [ 6488.709945] Lustre: DEBUG MARKER: == replay-single test 90: lfs find identifies the missing striped file segments ========================================================== 15:43:00 (1767040980) [ 6495.201686] Lustre: lustre-OST0001-osc-ffff990bd0a86000: Connection to lustre-OST0001 (at 192.168.203.127@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6495.208400] Lustre: Skipped 20 previous similar messages [ 6510.943697] Lustre: DEBUG MARKER: == replay-single test 93a: replay + reconnect ============ 15:43:22 (1767041002) [ 6558.687145] Lustre: 2402:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1767041034/real 1767041034] req@ffff990bd0872680 x1852870091234944/t0(0) o400->lustre-OST0000-osc-ffff990bd0a86000@192.168.203.127@tcp:28/4 lens 224/224 e 0 to 1 dl 1767041050 ref 1 fl Rpc:XQr/2c0/ffffffff rc 0/-1 job:'ptlrpcd_rcv.0' uid:0 gid:0 projid:4294967295 [ 6558.694012] Lustre: 2402:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 15 previous similar messages [ 6568.146614] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 6568.791907] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 6572.810732] Lustre: DEBUG MARKER: == replay-single test 93b: replay + reconnect on mds ===== 15:44:24 (1767041064) [ 6589.409817] LustreError: MGC192.168.203.127@tcp: Connection to MGS (at 192.168.203.127@tcp) was lost; in progress operations using this service will fail [ 6589.416128] LustreError: Skipped 7 previous similar messages [ 6589.421195] Lustre: Evicted from MGS (at 192.168.203.127@tcp) after server handle changed from 0xe79bd7b01ddc942a to 0xe79bd7b01ddc9eb1 [ 6589.426779] Lustre: Skipped 7 previous similar messages [ 6589.429974] Lustre: MGC192.168.203.127@tcp: Connection restored to 192.168.203.127@tcp (at 192.168.203.127@tcp) [ 6589.434603] Lustre: Skipped 26 previous similar messages [ 6676.259366] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6676.750689] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6680.456832] Lustre: DEBUG MARKER: == replay-single test complete, duration 6530 sec ======== 15:46:12 (1767041172) [ 6681.275300] Lustre: DEBUG MARKER: === replay-single: start cleanup 15:46:12 (1767041172) === [ 6684.617411] Lustre: DEBUG MARKER: === replay-single: finish cleanup 15:46:16 (1767041176) === [ 6714.814910] Lustre: DEBUG MARKER: oleg327-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 6715.363392] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 6717.146418] LustreError: 247710:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff990bd0a86000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6717.148875] LustreError: 247710:0:(lov_obd.c:783:lov_cleanup()) Skipped 1 previous similar message [ 6717.152158] LustreError: 247710:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [ 6717.153598] LustreError: 247710:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 6717.171111] Lustre: Unmounted lustre-client [ 6757.090416] Key type lgssc unregistered [ 6757.244932] LNet: 248393:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6757.252483] LNetError: 248393:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6757.267828] LNet: Removed LNI 192.168.203.27@tcp [ 6757.649204] Key type .llcrypt unregistered [ 6757.651152] Key type ._llcrypt unregistered