[ 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.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 1792948827 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 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2464 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2300 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022C0 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2374 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE2404 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE243C 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2300-0xbffe2373] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22ff] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2374-0xbffe2403] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe2404-0xbffe243b] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe243c-0xbffe2463] [ 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.001010] APIC: Switch to symmetric I/O mode setup [ 0.002367] x2apic enabled [ 0.003006] Switched APIC routing to physical x2apic. [ 0.004011] kvm-guest: setup PV IPIs [ 0.006986] ..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.007024] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008011] pid_max: default: 32768 minimum: 301 [ 0.010131] LSM: Security Framework initializing [ 0.011042] Yama: becoming mindful. [ 0.012031] SELinux: Initializing. [ 0.014041] *** VALIDATE selinux *** [ 0.023283] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.028497] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029147] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031031] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.032103] *** VALIDATE tmpfs *** [ 0.034416] *** VALIDATE proc *** [ 0.035243] *** VALIDATE cgroup *** [ 0.036007] *** VALIDATE cgroup2 *** [ 0.038062] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.039141] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.040009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.041028] Spectre V2 : User space: Vulnerable [ 0.042007] Speculative Store Bypass: Vulnerable [ 0.045380] debug: unmapping init [mem 0xffffffff8c459000-0xffffffff8c460fff] [ 0.048228] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.049741] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.050022] ... version: 2 [ 0.051010] ... bit width: 48 [ 0.052012] ... generic registers: 4 [ 0.053010] ... value mask: 0000ffffffffffff [ 0.054011] ... max period: 00007fffffffffff [ 0.055011] ... fixed-purpose events: 3 [ 0.056010] ... event mask: 000000070000000f [ 0.058226] rcu: Hierarchical SRCU implementation. [ 0.060476] smp: Bringing up secondary CPUs ... [ 0.061698] x86: Booting SMP configuration: [ 0.062025] .... node #0, CPUs: #1 #2 #3 [ 0.068129] smp: Brought up 1 node, 4 CPUs [ 0.070014] smpboot: Max logical packages: 1 [ 0.071079] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.097067] node 0 deferred pages initialised in 23ms [ 0.100162] devtmpfs: initialized [ 0.101234] x86/mm: Memory block size: 128MB [ 0.105132] gcov: version magic: 0x41383552 [ 0.107540] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.108092] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.109562] pinctrl core: initialized pinctrl subsystem [ 0.110296] [ 0.110885] ************************************************************* [ 0.111021] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.112020] ** ** [ 0.113013] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.114014] ** ** [ 0.115016] ** This means that this kernel is built to expose internal ** [ 0.116013] ** IOMMU data structures, which may compromise security on ** [ 0.117016] ** your system. ** [ 0.118018] ** ** [ 0.119014] ** If you see this message and you are not debugging the ** [ 0.120021] ** kernel, report this immediately to your vendor! ** [ 0.121016] ** ** [ 0.122013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.123016] ************************************************************* [ 0.124907] NET: Registered protocol family 16 [ 0.125578] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.126054] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.127058] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.128656] cpuidle: using governor menu [ 0.130476] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.133640] PCI: Using configuration type 1 for base access [ 0.135135] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.145355] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.146000] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.147506] cryptd: max_cpu_qlen set to 1000 [ 0.149285] ACPI: Added _OSI(Module Device) [ 0.150000] ACPI: Added _OSI(Processor Device) [ 0.150000] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.153017] ACPI: Added _OSI(Processor Aggregator Device) [ 0.158921] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.165915] ACPI: Interpreter enabled [ 0.167053] ACPI: PM: (supports S0 S3 S4 S5) [ 0.169010] ACPI: Using IOAPIC for interrupt routing [ 0.171173] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.174683] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.191366] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.193029] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.195021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.197068] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.201476] acpiphp: Slot [2] registered [ 0.202113] acpiphp: Slot [5] registered [ 0.203139] acpiphp: Slot [6] registered [ 0.204087] acpiphp: Slot [3] registered [ 0.206081] acpiphp: Slot [4] registered [ 0.207080] acpiphp: Slot [7] registered [ 0.208113] acpiphp: Slot [8] registered [ 0.209113] acpiphp: Slot [9] registered [ 0.210071] acpiphp: Slot [10] registered [ 0.211069] acpiphp: Slot [11] registered [ 0.212084] acpiphp: Slot [12] registered [ 0.213077] acpiphp: Slot [13] registered [ 0.214073] acpiphp: Slot [14] registered [ 0.215066] acpiphp: Slot [15] registered [ 0.217139] acpiphp: Slot [16] registered [ 0.218071] acpiphp: Slot [17] registered [ 0.219121] acpiphp: Slot [18] registered [ 0.220079] acpiphp: Slot [19] registered [ 0.222094] acpiphp: Slot [20] registered [ 0.223106] acpiphp: Slot [21] registered [ 0.224100] acpiphp: Slot [22] registered [ 0.226102] acpiphp: Slot [23] registered [ 0.227124] acpiphp: Slot [24] registered [ 0.228084] acpiphp: Slot [25] registered [ 0.230665] acpiphp: Slot [26] registered [ 0.233155] acpiphp: Slot [27] registered [ 0.234000] acpiphp: Slot [28] registered [ 0.239134] acpiphp: Slot [29] registered [ 0.243140] acpiphp: Slot [30] registered [ 0.246128] acpiphp: Slot [31] registered [ 0.250096] PCI host bridge to bus 0000:00 [ 0.255030] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.267030] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.268000] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.273026] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.280022] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.286024] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.287176] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.292988] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.299475] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.312016] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.321059] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.324019] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.326014] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.328019] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.330555] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.343440] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.347061] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.354939] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.367016] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.394017] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.409018] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.414000] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.422016] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.446031] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.538010] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.574753] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.594015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.614017] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.657016] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.686059] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.693443] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.695642] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.704601] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.714263] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.727096] iommu: Default domain type: Passthrough [ 0.732434] SCSI subsystem initialized [ 0.737659] ACPI: bus type USB registered [ 0.742119] usbcore: registered new interface driver usbfs [ 0.749119] usbcore: registered new interface driver hub [ 0.761090] usbcore: registered new device driver usb [ 0.770196] pps_core: LinuxPPS API ver. 1 registered [ 0.774011] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.783059] PTP clock support registered [ 0.789051] EDAC MC: Ver: 3.0.0 [ 0.790940] PCI: Using ACPI for IRQ routing [ 0.791696] NetLabel: Initializing [ 0.795028] NetLabel: domain hash size = 128 [ 0.796000] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.810116] NetLabel: unlabeled traffic allowed by default [ 0.815113] vgaarb: loaded [ 0.821304] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.822000] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.845319] clocksource: Switched to clocksource kvm-clock [ 1.374908] VFS: Disk quotas dquot_6.6.0 [ 1.376430] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.381381] *** VALIDATE ramfs *** [ 1.382630] *** VALIDATE hugetlbfs *** [ 1.387899] pnp: PnP ACPI init [ 1.397823] pnp: PnP ACPI: found 6 devices [ 1.463437] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.469395] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.478907] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.482995] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.486242] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.491040] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.503773] NET: Registered protocol family 2 [ 1.512347] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.529067] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.540896] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.548751] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.553132] TCP: Hash tables configured (established 65536 bind 65536) [ 1.556788] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.560824] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.566715] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.572030] NET: Registered protocol family 1 [ 1.576278] RPC: Registered named UNIX socket transport module. [ 1.581177] RPC: Registered udp transport module. [ 1.583439] RPC: Registered tcp transport module. [ 1.585278] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.588757] NET: Registered protocol family 44 [ 1.591548] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.601153] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.611514] pci 0000:00:00.0: quirk_passive_release+0x0/0x90 took 10155 usecs [ 1.618580] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.623821] PCI: CLS 0 bytes, default 64 [ 1.626199] Unpacking initramfs... [ 4.117343] hrtimer: interrupt took 3335956 ns [ 7.352810] debug: unmapping init [mem 0xffff8b75fcc64000-0xffff8b75fffcffff] [ 7.371623] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 7.398893] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 7.424793] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 11.570132] Initialise system trusted keyrings [ 11.586088] Key type blacklist registered [ 11.597609] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 11.663261] zbud: loaded [ 11.679844] *** VALIDATE nfs *** [ 11.686958] *** VALIDATE nfs4 *** [ 11.697724] pstore: using deflate compression [ 11.736583] Platform Keyring initialized [ 13.075204] NET: Registered protocol family 38 [ 13.077785] Key type asymmetric registered [ 13.080458] Asymmetric key parser 'x509' registered [ 13.083889] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 13.113871] io scheduler mq-deadline registered [ 13.116354] io scheduler kyber registered [ 13.118888] io scheduler bfq registered [ 13.121677] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 13.125810] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 13.131705] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 13.135655] ACPI: Power Button [PWRF] [ 13.147144] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 13.156880] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 13.172035] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 13.221618] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 13.259430] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 13.266559] Non-volatile memory driver v1.3 [ 13.268410] Linux agpgart interface v0.103 [ 13.344069] virtio_blk virtio1: [vda] 145840 512-byte logical blocks (74.7 MB/71.2 MiB) [ 13.363600] vda: detected capacity change from 0 to 74670080 [ 13.472197] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 13.481145] vdb: detected capacity change from 0 to 1073741824 [ 13.513364] libphy: Fixed MDIO Bus: probed [ 13.542059] usbcore: registered new interface driver usbserial_generic [ 13.546530] usbserial: USB Serial support registered for generic [ 13.552302] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 13.559220] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 13.563792] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 13.568218] mousedev: PS/2 mouse device common for all mice [ 13.574309] rtc_cmos 00:05: RTC can wake from S4 [ 13.584106] rtc_cmos 00:05: registered as rtc0 [ 13.585875] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 13.588276] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 13.594120] intel_pstate: CPU model not supported [ 13.607252] hid: raw HID events driver (C) Jiri Kosina [ 13.620322] usbcore: registered new interface driver usbhid [ 13.624202] usbhid: USB HID core driver [ 13.628498] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 13.639614] drop_monitor: Initializing network drop monitor service [ 13.639751] Initializing XFRM netlink socket [ 13.640167] NET: Registered protocol family 10 [ 13.655355] Segment Routing with IPv6 [ 13.682173] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 13.689667] NET: Registered protocol family 17 [ 13.690098] mpls_gso: MPLS GSO support [ 13.723963] RAS: Correctable Errors collector initialized. [ 13.726064] AVX version of gcm_enc/dec engaged. [ 13.727862] AES CTR mode by8 optimization enabled [ 14.229451] sched_clock: Marking stable (14229423377, 0)->(16061350145, -1831926768) [ 14.249637] registered taskstats version 1 [ 14.260678] Loading compiled-in X.509 certificates [ 14.271665] zswap: loaded using pool lzo/zbud [ 14.438577] Key type big_key registered [ 14.498747] Key type encrypted registered [ 14.510313] ima: No TPM chip found, activating TPM-bypass! [ 14.513272] ima: Allocated hash algorithm: sha1 [ 14.540894] ima: No architecture policies found [ 14.550965] evm: Initialising EVM extended attributes: [ 14.560035] evm: security.selinux [ 14.572266] evm: security.ima [ 14.575852] evm: security.capability [ 14.577119] evm: HMAC attrs: 0x1 [ 14.597451] rtc_cmos 00:05: setting system clock to 2026-08-10 13:49:20 UTC (1786369760) [ 14.646728] debug: unmapping init [mem 0xffffffff8d403000-0xffffffff8d5fffff] [ 14.704949] debug: unmapping init [mem 0xffffffff8c182000-0xffffffff8c458fff] [ 14.734196] Write protecting the kernel read-only data: 28672k [ 14.758794] debug: unmapping init [mem 0xffffffff8a803000-0xffffffff8a9fffff] [ 14.768697] debug: unmapping init [mem 0xffffffff8b114000-0xffffffff8b1fffff] [ 15.000131] 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) [ 15.038196] systemd[1]: Detected virtualization kvm. [ 15.047051] systemd[1]: Detected architecture x86-64. [ 15.060520] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 15.216787] systemd[1]: No hostname configured. [ 15.218956] systemd[1]: Set hostname to . [ 15.220935] random: systemd: uninitialized urandom read (16 bytes read) [ 15.223893] systemd[1]: Initializing machine ID from random generator. [ 15.822613] random: systemd: uninitialized urandom read (16 bytes read) [ 15.849113] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 15.889915] random: systemd: uninitialized urandom read (16 bytes read) [ 15.915508] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 15.937671] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Paths. [ 16.255399] urandom_read: 6 callbacks suppressed [ 16.255412] random: systemd: uninitialized urandom read (16 bytes read) [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Sockets. Starting Apply Kernel Variables... Starting Journal Service... [ OK ] Reached target Local File Systems. Starting Setup Virtual Console... [ OK ] Reached target Swap. Starting 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. [ OK ] Started Create Volatile Files and Directories. 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... [ 20.307036] device-mapper: uevent: version 1.0.3 [ 20.312146] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 25.025312] virtio_net virtio0 ens2: renamed from eth0 [ 25.483048] scsi host0: ata_piix [ 25.515247] scsi host1: ata_piix [ 25.517882] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 25.522418] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 31.106508] random: crng init done [ 34.564376] dracut-initqueue[604]: 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... [ 36.114701] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped dracut initqueue hook. [ 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 Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 43.236976] printk: systemd: 26 output lines suppressed due to ratelimiting [ 44.349553] SELinux: Disabled at runtime. [ 44.495053] 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) [ 44.575641] systemd[1]: Detected virtualization kvm. [ 44.602815] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 46.474644] systemd[1]: initrd-switch-root.service: Succeeded. [ 46.479616] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 46.487299] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 46.495973] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 46.499608] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 46.509035] systemd[1]: Starting Journal Service... Starting Journal Service... [ 46.522235] systemd[1]: Activating swap /dev/disk/by-label/SWAP... Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on udev Control Socket. [ OK ] Started Forward Password Requests to Wall Directory Watch. Mounting Kernel Debug File System... [ OK [[ 46.588992] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS 0m] Listening on Process Core Dump Socket. [ OK ] Created slice User and Session Slice. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Reached target Slices. [ OK ] Stopped target Switch Root. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Created slice system-serial\x2dgetty.slice. Mounting Huge Pages File System... [ OK ] Created slice system-getty.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Stopped target Initrd Root File System. Starting Apply Kernel Variables... [ OK ] Listening on initctl Compatibility Named Pipe. Starting Remount Root and Kernel File Systems... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Reached target rpc_pipefs.target. Mounting POSIX Message Queue File System... [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug 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 ] Mounted POSIX Message Queue File System. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 48.496974] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 49.896858] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 50.063600] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 52.245943] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 52.568356] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (8s / no limit) [** ] A start job is running for Configur…-only root support (8s / no limit) [*** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…-only root support (9s / no limit) [ *** ] A start job is running for Configur…only root support (10s / no limit) [ ***] A start job is running for Configur…only root support (10s / no limit) [ **] A start job is running for Configur…only root support (11s / no limit) [ *] A start job is running for Configur…only root support (11s / no limit) [ **] A start job is running for Configur…only root support (12s / no limit) [ ***] A start job is running for Configur…only root support (12s / no limit) [ *** ] A start job is running for Configur…only root support (13s / no limit) [ *** ] A start job is running for Configur…only root support (13s / no limit)[ 60.181721] Key type dns_resolver registered [*** ] A start job is running for Configur…only root support (14s / no limit) [** ] A start job is running for Configur…only root support (14s / no limit) [* ] A start job is running for Configur…only root support (15s / no limit)[ 61.339684] NFS: Registering the id_resolver key type [ 61.342178] Key type id_resolver registered [ 61.344034] Key type id_legacy registered [** ] A start job is running for Configur…only root support (15s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ 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 Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Daily Cleanup of Temporary Directories. Starting Login Service... [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning 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 OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Login Service. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg144-client login: [ 124.286312] libcfs: loading out-of-tree module taints kernel. [ 124.563438] Key type ._llcrypt registered [ 124.569086] Key type .llcrypt registered [ 125.024572] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 125.041882] alg: No test for adler32 (adler32-zlib) [ 126.345238] Lustre: Lustre: Build Version: 2.17.56_50_g6d2b241 [ 127.306601] LNet: Added LNI 192.168.201.44@tcp [8/256/0/180] [ 129.055177] Key type lgssc registered [ 131.039286] Lustre: Echo OBD driver; http://www.lustre.org/ [ 260.988359] Lustre: Mounted lustre-client - version 2.17.56_50_g6d2b241 [ 266.324708] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 282.313572] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing check_logdir /tmp/testlogs/ [ 286.690458] Lustre: lustre-OST0000-osc-ffff8b7644ef1000: disconnect after 23s idle [ 287.940272] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing yml_node [ 292.454682] Lustre: DEBUG MARKER: Client: 2.17.56.50 [ 295.936565] Lustre: DEBUG MARKER: MDS: 2.17.56.50 [ 298.497116] Lustre: DEBUG MARKER: OSS: 2.17.56.50 [ 300.266773] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Mon Aug 10 09:54:04 EDT 2026 [ 317.177970] Lustre: DEBUG MARKER: excepting tests: 27 40a [ 318.688879] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 320.402024] Lustre: DEBUG MARKER: === sanityn: start setup 09:54:24 (1786370064) === [ 320.997257] Lustre: Mounted lustre-client - version 2.17.56_50_g6d2b241 [ 326.454401] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing check_config_client /mnt/lustre [ 344.626881] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 357.584697] Lustre: DEBUG MARKER: === sanityn: finish setup 09:55:01 (1786370101) === [ 360.385954] Lustre: DEBUG MARKER: == sanityn test 0: do_node_vp() and do_facet_vp() do the right thing ========================================================== 09:55:04 (1786370104) [ 369.267240] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 09:55:14 (1786370114) [ 376.012558] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 09:55:20 (1786370120) [ 382.982230] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 09:55:27 (1786370127) [ 390.307971] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 09:55:34 (1786370134) [ 397.193966] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 09:55:41 (1786370141) [ 404.063761] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 09:55:48 (1786370148) [ 410.130817] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 09:55:54 (1786370154) [ 411.494298] Lustre: DEBUG MARKER: SKIP: sanityn test_2f needs >= 2 MDTs [ 413.284652] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 09:55:57 (1786370157) [ 420.558415] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 09:56:05 (1786370165) [ 427.221974] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 09:56:11 (1786370171) [ 433.631868] Lustre: lustre-OST0001-osc-ffff8b7644ef1000: disconnect after 20s idle [ 433.635854] Lustre: Skipped 1 previous similar message [ 434.710076] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 09:56:19 (1786370179) [ 441.272096] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 09:56:26 (1786370186) [ 448.234277] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 09:56:32 (1786370192) [ 448.998740] Lustre: lustre-OST0000-osc-ffff8b766094c000: disconnect after 20s idle [ 455.408296] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 09:56:39 (1786370199) [ 460.973499] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 09:56:45 (1786370205) [ 464.351163] Lustre: lustre-OST0001-osc-ffff8b7644ef1000: disconnect after 20s idle [ 468.783369] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 09:56:53 (1786370213) [ 476.404210] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 09:57:00 (1786370220) [ 484.820864] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 09:57:09 (1786370229) [ 492.151495] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 09:57:16 (1786370236) [ 499.929468] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 09:57:24 (1786370244) [ 500.666342] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205272502304 file: /mnt/lustre/lockdir/lockfile=144115205272502302 [ 645.495631] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 09:59:49 (1786370389) [ 655.074676] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 09:59:59 (1786370399) [ 661.671555] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 10:00:06 (1786370406) [ 668.022403] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 10:00:12 (1786370412) [ 674.595126] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 10:00:19 (1786370419) [ 681.172627] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 10:00:25 (1786370425) [ 682.988920] Lustre: DEBUG MARKER: chmod [ 689.889678] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 10:00:34 (1786370434) [ 725.983343] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7531520KB free > 800000KB, increase MAXFREE (or reduce fs size) [ 743.242535] Lustre: DEBUG MARKER: == sanityn test 16a: 500 iterations of dual-mount fsx ==== 10:01:27 (1786370487) [ 798.556323] Lustre: DEBUG MARKER: == sanityn test 16b: 500 iterations of dual-mount fsx at small size ========================================================== 10:02:23 (1786370543) [ 826.325719] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 10:02:51 (1786370571) [ 828.817467] Lustre: DEBUG MARKER: SKIP: sanityn test_16c dio on ldiskfs only [ 830.397664] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 10:02:55 (1786370575) [ 873.952981] Lustre: lustre-OST0000-osc-ffff8b766094c000: disconnect after 20s idle [ 878.631436] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 10:03:43 (1786370623) [ 885.459520] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 10:03:50 (1786370630) [ 886.759241] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 886.852921] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 886.958462] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.041766] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.128667] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.182431] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.242655] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.310170] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.396474] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.480279] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.577405] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.691188] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.753245] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.839068] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.950585] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 887.992621] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.061655] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.125695] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.204293] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.250433] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.345784] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.446624] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.513369] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.564744] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.614436] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.677194] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.727331] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.782987] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.859233] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 888.937982] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.058878] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.192827] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.300551] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.390477] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.457755] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.538024] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.633030] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.707401] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.802342] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.874521] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 889.963820] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.051971] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.124855] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.207219] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.286824] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.368740] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.435973] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.506926] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.584429] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.652719] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.726095] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.789331] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.866695] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 890.972380] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.040793] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.145472] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.235407] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.310452] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.410973] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.489464] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.585657] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.678681] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.734033] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.797259] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.894367] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 891.976087] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.045705] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.128944] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.225912] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.319891] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.413281] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.448772] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.504980] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.576326] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.651897] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.719460] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.803926] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.862769] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.922500] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 892.997679] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.076514] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.153860] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.242408] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.328834] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.391133] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.461473] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.566340] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.668118] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.747233] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.828610] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 893.928490] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.019347] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.111780] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.213831] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.305453] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.401921] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.486610] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.556287] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.636509] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.700565] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.781205] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.872850] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 894.952276] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.047410] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.145784] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.230585] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.338163] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.421930] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.509627] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.578935] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.650711] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.721863] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.785227] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.869464] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 895.937258] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.007315] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.073086] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.245612] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.404643] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.562712] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.674228] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.790331] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.897444] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 896.967782] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.076827] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.197289] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.306231] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.381966] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.468596] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.543497] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.604924] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.663176] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.753993] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.823404] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 897.912462] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.032618] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.113589] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.208925] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.303111] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.392443] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.481045] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.580151] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.684831] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.766505] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.850822] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.927787] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 898.997908] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.093474] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.195655] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.298157] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.370578] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.456333] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.553416] Lustre: lustre-OST0001-osc-ffff8b766094c000: disconnect after 20s idle [ 899.563152] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.633079] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.712362] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.817290] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 899.897257] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.033867] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.148905] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.259157] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.339941] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.402776] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.479299] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.583160] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.665420] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.767122] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.843340] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 900.965626] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.099086] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.202482] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.293910] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.422766] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.529156] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.620892] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.740322] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.839796] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 901.939495] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.040664] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.158047] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.261527] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.349595] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.457220] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.567237] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.686975] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.783346] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.873984] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 902.985707] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.084360] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.207459] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.348513] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.494399] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.596638] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.700050] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.803221] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 903.903228] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.017627] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.118612] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.225268] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.356735] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.458585] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.577885] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.642333] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.763220] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.883494] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 904.996347] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 905.123091] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 905.256221] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 905.358531] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 905.467411] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 905.593665] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 905.701690] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 905.804808] rw_seq_cst_vs_d (29685): drop_caches: 3 [ 914.188291] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 10:04:18 (1786370658) [ 915.104960] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.174283] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.214795] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.274569] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.364944] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.417776] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.468534] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.530078] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.601497] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.653280] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.726660] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.859892] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 915.910148] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 916.152945] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 916.210839] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 916.318122] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 916.523765] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 916.713220] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 916.762487] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 916.988139] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 917.091044] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 917.157205] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 917.266615] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 917.369671] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 917.532890] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 917.686767] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 917.875119] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 918.036896] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 918.245705] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 918.417850] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 918.619463] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 918.706083] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 918.911615] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 919.000442] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 919.273924] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 919.433724] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 919.508164] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 919.601769] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 919.658085] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 919.919602] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 920.147846] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 920.342833] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 920.457377] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 920.677096] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 920.945204] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 921.091735] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 921.206952] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 921.355640] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 921.479599] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 921.567849] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 921.643575] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 921.888555] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.077268] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.138785] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.288872] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.362624] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.568158] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.686238] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.769338] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 922.924180] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.041871] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.255721] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.318186] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.360763] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.407664] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.506654] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.592774] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.662883] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 923.885674] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 924.050644] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 924.125875] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 924.457721] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 924.615231] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 924.680687] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 924.883640] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.037797] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.160939] Lustre: lustre-OST0000-osc-ffff8b766094c000: disconnect after 20s idle [ 925.179617] Lustre: Skipped 1 previous similar message [ 925.292101] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.452292] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.550828] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.706097] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.826425] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.865577] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 925.908933] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.039858] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.218370] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.310984] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.418084] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.562916] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.691828] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.769308] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 926.925853] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 927.079295] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 927.229450] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 927.286830] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 927.489253] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 927.561649] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 927.800582] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.037728] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.200816] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.269845] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.419790] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.511763] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.575145] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.654328] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.803912] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.902698] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 928.988086] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.191699] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.264640] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.323286] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.446579] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.505421] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.654656] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.827585] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.951985] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 929.995737] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.125795] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.195427] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.235239] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.275241] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.349738] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.504315] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.864903] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 930.916801] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.135123] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.242249] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.296292] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.328988] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.532906] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.654844] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.709520] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 931.953686] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.109768] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.290425] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.381533] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.523816] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.599124] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.642450] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.787432] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.858059] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.904660] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 932.967452] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.171553] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.325739] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.412259] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.545209] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.643426] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.821309] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.912894] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 933.982462] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 934.031140] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 934.146798] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 934.262229] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 934.362494] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 934.472772] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 934.548612] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 934.638874] rw_seq_cst_vs_d (30263): drop_caches: 3 [ 942.831965] Lustre: DEBUG MARKER: == sanityn test 16h: mmap read after truncate file ======= 10:04:47 (1786370687) [ 949.947486] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 10:04:54 (1786370694) [ 957.036495] Lustre: DEBUG MARKER: == sanityn test 16j: race dio with buffered i/o ========== 10:05:01 (1786370701) [ 1000.534858] Lustre: DEBUG MARKER: == sanityn test 16k: Parallel FSX and drop caches should not panic ========================================================== 10:05:45 (1786370745) [ 1001.101277] bash (32712): drop_caches: 3 [ 1004.432270] bash (32712): drop_caches: 3 [ 1007.869218] bash (32712): drop_caches: 3 [ 1012.085521] bash (32712): drop_caches: 3 [ 1015.207249] bash (32712): drop_caches: 3 [ 1018.427915] bash (32712): drop_caches: 3 [ 1021.657781] bash (32712): drop_caches: 3 [ 1024.810281] bash (32712): drop_caches: 3 [ 1027.959673] bash (32712): drop_caches: 3 [ 1031.121256] bash (32712): drop_caches: 3 [ 1034.217452] bash (32712): drop_caches: 3 [ 1037.352428] bash (32712): drop_caches: 3 [ 1040.504490] bash (32712): drop_caches: 3 [ 1043.630582] bash (32712): drop_caches: 3 [ 1046.788976] bash (32712): drop_caches: 3 [ 1049.952263] bash (32712): drop_caches: 3 [ 1054.780344] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 10:06:39 (1786370799) [ 1064.232876] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 10:06:49 (1786370809) [ 1095.897402] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 10:07:20 (1786370840) [ 1098.226975] Lustre: DEBUG MARKER: SKIP: sanityn test_19 not cache-capable obdfilter [ 1100.553235] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 10:07:24 (1786370844) [ 1107.496995] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 10:07:32 (1786370852) [ 1109.473134] Lustre: lustre-OST0001-osc-ffff8b7644ef1000: disconnect after 22s idle [ 1109.475211] Lustre: Skipped 1 previous similar message [ 1114.287146] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 10:07:38 (1786370858) [ 1182.933978] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 10:08:47 (1786370927) [ 1189.412707] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 10:08:54 (1786370934) [ 1195.810204] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 10:09:00 (1786370940) [ 1202.260059] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 10:09:07 (1786370947) [ 1203.733515] Lustre: DEBUG MARKER: SKIP: sanityn test_25b needs >= 2 MDTs [ 1205.282859] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 10:09:10 (1786370950) [ 1211.879939] Lustre: lustre-OST0001-osc-ffff8b7644ef1000: disconnect after 22s idle [ 1211.889252] Lustre: Skipped 4 previous similar messages [ 1212.086667] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 10:09:16 (1786370956) [ 1220.557408] Lustre: DEBUG MARKER: == sanityn test 26c: set-in-past on open file is not lost on close ========================================================== 10:09:24 (1786370964) [ 1227.708845] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 1228.876282] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 10:09:33 (1786370973) [ 1236.494562] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 10:09:41 (1786370981) [ 1236.756926] Lustre: *** cfs_fail_loc=314, val=0*** [ 1237.795731] Lustre: *** cfs_fail_loc=314, val=0*** [ 1237.797601] Lustre: Skipped 2 previous similar messages [ 1243.374422] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 10:09:48 (1786370988) [ 1257.131171] Lustre: *** cfs_fail_loc=314, val=0*** [ 1257.247911] LustreError: lustre-OST0000-osc-ffff8b766094c000: operation ldlm_enqueue to node 192.168.201.144@tcp failed: rc = -107 [ 1257.258968] Lustre: lustre-OST0000-osc-ffff8b766094c000: Connection to lustre-OST0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1257.273836] LustreError: lustre-OST0000-osc-ffff8b766094c000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1257.299378] LustreError: 42006:0:(ldlm_resource.c:1207:ldlm_resource_complain()) lustre-OST0000-osc-ffff8b766094c000: namespace resource [0x240000400:0x35:0x0].0x0 (ffff8b766057f300) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 1257.321952] Lustre: lustre-OST0000-osc-ffff8b766094c000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 1263.219300] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 10:10:07 (1786371007) [ 1263.611603] LustreError: 42588:0:(file.c:850:ll_intent_file_open()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 1266.631598] LustreError: 42588:0:(file.c:850:ll_intent_file_open()) cfs_fail_timeout id 1419 awake [ 1271.655791] Lustre: DEBUG MARKER: == sanityn test 31s: open should not revalidate invalid dentry ========================================================== 10:10:16 (1786371016) [ 1278.202674] Lustre: DEBUG MARKER: == sanityn test 31t: getattr should not revalidate invalid dentry ========================================================== 10:10:23 (1786371023) [ 1284.418535] Lustre: DEBUG MARKER: == sanityn test 32b: lockless i/o ======================== 10:10:29 (1786371029) [ 1285.893102] Lustre: DEBUG MARKER: SKIP: sanityn test_32b max_nolock_bytes is removed >= 2.17.53 [ 1287.480682] Lustre: DEBUG MARKER: == sanityn test 32c: contention detection ================ 10:10:32 (1786371032) [ 1309.646524] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 1311.240417] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 10:10:55 (1786371055) [ 1312.879480] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 1314.384521] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-on-Lock-Cancel ========================================================== 10:10:59 (1786371059) [ 1315.648514] Lustre: DEBUG MARKER: SKIP: sanityn test_33c needs >= 2 MDTs [ 1317.162674] Lustre: DEBUG MARKER: == sanityn test 33d: dependent transactions should trigger COS ========================================================== 10:11:01 (1786371061) [ 1318.580921] Lustre: DEBUG MARKER: SKIP: sanityn test_33d needs >= 2 MDTs [ 1320.130814] Lustre: DEBUG MARKER: == sanityn test 33e: independent transactions shouldn't trigger COS ========================================================== 10:11:04 (1786371064) [ 1321.604982] Lustre: DEBUG MARKER: SKIP: sanityn test_33e needs >= 2 MDTs [ 1322.947438] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 10:11:07 (1786371067) [ 1374.665418] Lustre: lustre-OST0001-osc-ffff8b766094c000: Connection to lustre-OST0001 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1374.681706] LustreError: lustre-OST0001-osc-ffff8b766094c000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1374.695333] LustreError: lustre-OST0001-osc-ffff8b7644ef1000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1374.699218] Lustre: lustre-OST0001-osc-ffff8b766094c000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 1374.708984] Lustre: Skipped 1 previous similar message [ 1390.017263] Lustre: lustre-OST0000-osc-ffff8b7644ef1000: Connection to lustre-OST0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1390.026162] Lustre: Skipped 1 previous similar message [ 1390.032899] LustreError: lustre-OST0000-osc-ffff8b7644ef1000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1390.042380] Lustre: lustre-OST0000-osc-ffff8b7644ef1000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 1396.193227] Lustre: lustre-OST0001-osc-ffff8b7644ef1000: disconnect after 22s idle [ 1396.200995] Lustre: Skipped 5 previous similar messages [ 1407.447040] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff8b7644ef1000.ost_server_uuid 50 [ 1408.321338] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8b7644ef1000.ost_server_uuid in FULL state after 0 sec [ 1412.780175] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff8b7644ef1000.ost_server_uuid 50 [ 1413.967539] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff8b7644ef1000.ost_server_uuid in IDLE state after 0 sec [ 1419.574382] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff8b7644ef1000.ost_server_uuid 50 [ 1420.567349] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8b7644ef1000.ost_server_uuid in IDLE state after 0 sec [ 1424.428620] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff8b7644ef1000.ost_server_uuid 50 [ 1425.394757] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff8b7644ef1000.ost_server_uuid in IDLE state after 0 sec [ 1433.650549] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff8b7644ef1000.ost_server_uuid 50 [ 1434.737363] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8b7644ef1000.ost_server_uuid in IDLE state after 0 sec [ 1438.940893] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff8b7644ef1000.ost_server_uuid 50 [ 1439.887800] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff8b7644ef1000.ost_server_uuid in IDLE state after 0 sec [ 1441.354525] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 10:13:06 (1786371186) [ 1443.169783] Lustre: DEBUG MARKER: Race attempt 0 [ 1445.590734] Lustre: DEBUG MARKER: Wait for 50468 50541 for 60 sec... [ 1510.397219] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 10:14:15 (1786371255) [ 1517.402932] Lustre: DEBUG MARKER: start test - cycle (0) [ 1543.310910] Lustre: DEBUG MARKER: start test - cycle (1) [ 1568.198328] Lustre: DEBUG MARKER: start test - cycle (2) [ 1593.887663] Lustre: DEBUG MARKER: start test - cycle (3) [ 1619.563649] Lustre: DEBUG MARKER: start test - cycle (4) [ 1645.123364] Lustre: DEBUG MARKER: start test - cycle (5) [ 1668.770951] Lustre: DEBUG MARKER: start test - cycle (6) [ 1672.672609] Lustre: lustre-OST0001-osc-ffff8b766094c000: disconnect after 20s idle [ 1672.681193] Lustre: Skipped 5 previous similar messages [ 1695.319960] Lustre: DEBUG MARKER: start test - cycle (7) [ 1720.196429] Lustre: DEBUG MARKER: start test - cycle (8) [ 1744.967354] Lustre: DEBUG MARKER: start test - cycle (9) [ 1767.206957] Lustre: DEBUG MARKER: start test - cycle (10) [ 1796.327691] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 10:19:01 (1786371541) [ 1859.843908] Lustre: DEBUG MARKER: == sanityn test 39a: file mtime does not change after rename ========================================================== 10:20:04 (1786371604) [ 1864.812696] Lustre: DEBUG MARKER: == sanityn test 39b: file mtime the same on clients with/out lock ========================================================== 10:20:09 (1786371609) [ 1870.708180] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 10:20:15 (1786371615) [ 1876.072684] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 10:20:21 (1786371621) [ 1876.331861] Lustre: *** cfs_fail_loc=411, val=0*** [ 1880.352852] Lustre: DEBUG MARKER: SKIP: sanityn test_40a skipping ALWAYS excluded test 40a [ 1881.472686] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 10:20:26 (1786371626) [ 1900.280377] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 10:20:43 (1786371643) [ 1923.177346] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 10:21:07 (1786371667) [ 1948.221400] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 10:21:32 (1786371692) [ 1967.472427] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 10:21:51 (1786371711) [ 1981.553668] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 10:22:05 (1786371725) [ 1994.234774] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 10:22:18 (1786371738) [ 2006.553684] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 10:22:31 (1786371751) [ 2019.553198] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 10:22:44 (1786371764) [ 2032.655901] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 10:22:57 (1786371777) [ 2044.986943] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 10:23:09 (1786371789) [ 2058.681472] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 10:23:23 (1786371803) [ 2072.608808] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 10:23:37 (1786371817) [ 2689.503247] Lustre: lustre-OST0000-osc-ffff8b766094c000: disconnect after 22s idle [ 2689.508417] Lustre: Skipped 15 previous similar messages [ 2992.568926] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 10:38:57 (1786372737) [ 2999.680225] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 10:39:04 (1786372744) [ 3006.205810] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 10:39:11 (1786372751) [ 3012.625173] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 10:39:17 (1786372757) [ 3019.421308] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 10:39:24 (1786372764) [ 3026.058313] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 10:39:31 (1786372771) [ 3032.630451] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 10:39:37 (1786372777) [ 3039.829924] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 10:39:45 (1786372785) [ 3046.964710] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 10:39:52 (1786372792) [ 3081.155851] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 10:40:26 (1786372826) [ 3088.012814] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 10:40:33 (1786372833) [ 3094.690599] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 10:40:39 (1786372839) [ 3101.143755] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 10:40:46 (1786372846) [ 3108.431244] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 10:40:53 (1786372853) [ 3115.674346] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 10:41:00 (1786372860) [ 3122.648898] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 10:41:07 (1786372867) [ 3129.216842] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 10:41:14 (1786372874) [ 3129.936497] Lustre: DEBUG MARKER: SKIP: sanityn test_43i needs >= 2 MDTs [ 3130.748260] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 10:41:15 (1786372875) [ 3244.196494] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 10:43:09 (1786372989) [ 3411.424130] Lustre: lustre-OST0000-osc-ffff8b7644ef1000: disconnect after 22s idle [ 3411.428454] Lustre: Skipped 5 previous similar messages [ 4015.026794] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 10:56:00 (1786373760) [ 4023.408692] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 10:56:08 (1786373768) [ 4025.823558] Lustre: lustre-OST0000-osc-ffff8b766094c000: disconnect after 23s idle [ 4025.827786] Lustre: Skipped 2 previous similar messages [ 4031.851377] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 10:56:16 (1786373776) [ 4039.543646] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 10:56:24 (1786373784) [ 4047.938982] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 10:56:33 (1786373793) [ 4056.273740] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 10:56:41 (1786373801) [ 4064.562131] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 10:56:49 (1786373809) [ 4074.379909] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 10:56:59 (1786373819) [ 4083.057739] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 10:57:08 (1786373828) [ 4083.919833] Lustre: DEBUG MARKER: SKIP: sanityn test_44i needs >= 2 MDTs [ 4084.896594] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 10:57:10 (1786373830) [ 4140.031890] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 10:58:05 (1786373885) [ 4146.074874] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 10:58:11 (1786373891) [ 4152.128895] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 10:58:17 (1786373897) [ 4157.968730] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 10:58:23 (1786373903) [ 4163.824204] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 10:58:29 (1786373909) [ 4169.581886] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 10:58:34 (1786373914) [ 4175.195353] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 10:58:40 (1786373920) [ 4180.159981] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 10:58:45 (1786373925) [ 4180.647570] Lustre: DEBUG MARKER: SKIP: sanityn test_45i needs >= 2 MDTs [ 4181.189869] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 10:58:46 (1786373926) [ 4660.703435] Lustre: lustre-OST0000-osc-ffff8b7644ef1000: disconnect after 21s idle [ 4660.708063] Lustre: Skipped 6 previous similar messages [ 4970.760471] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 11:11:55 (1786374715) [ 4979.982211] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 11:12:04 (1786374724) [ 4991.290789] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 11:12:16 (1786374736) [ 5000.903334] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 11:12:25 (1786374745) [ 5008.005781] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 11:12:33 (1786374753) [ 5014.557805] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 11:12:39 (1786374759) [ 5021.372962] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 11:12:46 (1786374766) [ 5027.766849] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 11:12:53 (1786374773) [ 5034.508985] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 11:12:59 (1786374779) [ 5035.285716] Lustre: DEBUG MARKER: SKIP: sanityn test_46i needs >= 2 MDTs [ 5036.110414] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 11:13:01 (1786374781) [ 5036.791939] Lustre: DEBUG MARKER: SKIP: sanityn test_47a needs >= 2 MDTs [ 5037.490206] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 11:13:02 (1786374782) [ 5038.160159] Lustre: DEBUG MARKER: SKIP: sanityn test_47b needs >= 2 MDTs [ 5039.009302] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 11:13:04 (1786374784) [ 5039.645832] Lustre: DEBUG MARKER: SKIP: sanityn test_47c needs >= 2 MDTs [ 5040.439308] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 11:13:05 (1786374785) [ 5041.096363] Lustre: DEBUG MARKER: SKIP: sanityn test_47d needs >= 2 MDTs [ 5041.956400] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 11:13:07 (1786374787) [ 5042.617889] Lustre: DEBUG MARKER: SKIP: sanityn test_47e needs >= 2 MDTs [ 5043.481307] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 11:13:08 (1786374788) [ 5044.186771] Lustre: DEBUG MARKER: SKIP: sanityn test_47f needs >= 2 MDTs [ 5044.982128] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 11:13:10 (1786374790) [ 5045.649947] Lustre: DEBUG MARKER: SKIP: sanityn test_47g needs >= 2 MDTs [ 5046.488629] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 11:13:11 (1786374791) [ 5046.672907] LustreError: 21461:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 sleeping for 2000ms [ 5048.759185] LustreError: 21461:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 awake [ 5054.582321] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 11:13:19 (1786374799) [ 5059.645339] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 11:13:24 (1786374804) [ 5059.774926] LustreError: 219430:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 5063.841117] LustreError: 219430:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 5063.863591] LustreError: 219430:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 5067.928280] LustreError: 219430:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 5067.971810] LustreError: 219436:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 5072.031365] LustreError: 219436:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 5074.897325] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 11:13:40 (1786374820) [ 5082.432365] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 11:13:47 (1786374827) [ 5086.263397] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 11:13:51 (1786374831) [ 5091.196840] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 11:13:56 (1786374836) [ 5116.072632] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 11:14:21 (1786374861) [ 5124.016978] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 11:14:29 (1786374869) [ 5132.040660] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 11:14:37 (1786374877) [ 5145.411782] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 11:14:50 (1786374890) [ 5155.629257] Lustre: DEBUG MARKER: == sanityn test 55e: rename race AB/BA under the same parent dir ========================================================== 11:15:00 (1786374900) [ 5156.199501] Lustre: DEBUG MARKER: SKIP: sanityn test_55e needs >= 2 MDTs [ 5156.881858] Lustre: DEBUG MARKER: == sanityn test 55f: rename: (P1/A -> P2/B) race with (P2/B -> P1/A) ========================================================== 11:15:02 (1786374902) [ 5170.591986] Lustre: DEBUG MARKER: == sanityn test 55g: rename: race with trylock =========== 11:15:15 (1786374915) [ 5186.249457] Lustre: DEBUG MARKER: == sanityn test 56a: test llverdev with single large stripe ========================================================== 11:15:31 (1786374931) [ 5227.817372] Lustre: DEBUG MARKER: == sanityn test 56b: test llverdev and partial verify of wide stripe file ========================================================== 11:16:13 (1786374973) [ 5269.511399] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 11:16:54 (1786375014) [ 5271.591677] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 5273.692738] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 11:16:59 (1786375019) [ 5276.605630] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 11:17:02 (1786375022) [ 5277.306227] Lustre: DEBUG MARKER: SKIP: sanityn test_71a ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 5277.927719] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 11:17:03 (1786375023) [ 5278.590683] Lustre: DEBUG MARKER: SKIP: sanityn test_71b ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 5279.183623] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 11:17:04 (1786375024) [ 5279.771970] Lustre: DEBUG MARKER: SKIP: sanityn test_71c support only ldiskfs ost [ 5280.391031] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 11:17:05 (1786375025) [ 5281.098953] Lustre: DEBUG MARKER: SKIP: sanityn test_71d ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 5281.634047] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 11:17:07 (1786375027) [ 5283.744119] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 11:17:09 (1786375029) [ 5285.922053] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 11:17:11 (1786375031) [ 5288.990503] LustreError: lustre-MDT0000-mdc-ffff8b766094c000: operation ldlm_enqueue to node 192.168.201.144@tcp failed: rc = -35 [ 5292.001290] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 11:17:17 (1786375037) [ 5292.138389] LustreError: 2378:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d sleeping for 2000ms [ 5294.223155] LustreError: 2378:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d awake [ 5299.094977] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 11:17:24 (1786375044) [ 5319.398973] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 11:17:44 (1786375064) [ 5322.439672] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 11:17:47 (1786375067) [ 5326.832166] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 11:17:52 (1786375072) [ 5331.660423] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 11:17:57 (1786375077) [ 5336.491436] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 11:18:01 (1786375081) [ 5341.663292] Lustre: lustre-OST0000-osc-ffff8b766094c000: disconnect after 21s idle [ 5341.665558] Lustre: Skipped 4 previous similar messages [ 5344.266565] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 11:18:09 (1786375089) [ 5351.404461] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 11:18:16 (1786375096) [ 5354.942495] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 11:18:20 (1786375100) [ 5358.701527] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 11:18:24 (1786375104) [ 5365.813711] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 11:18:31 (1786375111) [ 5415.790769] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 11:19:20 (1786375160) [ 5568.999086] Lustre: DEBUG MARKER: == sanityn test 77jb: check TBF-UID/GID NRS policy on files that don't belong to us ========================================================== 11:21:52 (1786375312) [ 5725.939613] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with UID/GID/JobID/OPCode expression ========================================================== 11:24:30 (1786375470) [ 5961.184656] Lustre: lustre-OST0000-osc-ffff8b7644ef1000: disconnect after 22s idle [ 5961.189598] Lustre: Skipped 18 previous similar messages [ 6173.817536] Lustre: DEBUG MARKER: == sanityn test 77kb: Check different granular TBF type combination: jobid+opcode ========================================================== 11:31:58 (1786375918) [ 6223.313288] Lustre: DEBUG MARKER: == sanityn test 77kc: Check different granular TBF type combination: nid+opcode ========================================================== 11:32:47 (1786375967) [ 6275.009891] Lustre: DEBUG MARKER: == sanityn test 77kd: Check different granular TBF type combination: nid+jobid ========================================================== 11:33:39 (1786376019) [ 6319.510264] Lustre: DEBUG MARKER: == sanityn test 77ke: Check different granular TBF type combination: jobid+opcode ========================================================== 11:34:23 (1786376063) [ 6412.169906] Lustre: DEBUG MARKER: == sanityn test 77kf: Check different granular TBF type combination: uid+gid ========================================================== 11:35:56 (1786376156) [ 6486.505567] Lustre: DEBUG MARKER: == sanityn test 77kg: check different granular TBF type combination: uid+opcode ========================================================== 11:37:11 (1786376231) [ 6575.583332] Lustre: lustre-OST0000-osc-ffff8b7644ef1000: disconnect after 21s idle [ 6575.588274] Lustre: Skipped 20 previous similar messages [ 6623.968398] Lustre: DEBUG MARKER: == sanityn test 77kh: Verify that Project ID support for NRS TBF rule ========================================================== 11:39:28 (1786376368) [ 6627.820570] Lustre: Unmounted lustre-client [ 6631.410385] Lustre: Unmounted lustre-client [ 6715.401885] Lustre: Mounted lustre-client - version 2.17.56_50_g6d2b241 [ 6717.832289] Lustre: Mounted lustre-client - version 2.17.56_50_g6d2b241 [ 6720.440621] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6825.156952] Lustre: DEBUG MARKER: == sanityn test 77ki: Add rule with unsupported TBF type should fail for generic TBF ========================================================== 11:42:49 (1786376569) [ 6839.917635] Lustre: DEBUG MARKER: == sanityn test 77kj: Verify nodemap support for NRS TBF rule ========================================================== 11:43:04 (1786376584) [ 7007.006994] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 11:45:51 (1786376751) [ 7015.472249] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 11:46:00 (1786376760) [ 7072.221671] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 11:46:56 (1786376816) [ 7154.613563] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 11:48:19 (1786376899) [ 7165.116533] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 11:48:29 (1786376909) [ 7260.989394] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 11:50:05 (1786377005) [ 7288.575468] Lustre: DEBUG MARKER: == sanityn test 77r: Change type of tbf policy at run time ========================================================== 11:50:33 (1786377033) [ 7339.588324] Lustre: DEBUG MARKER: == sanityn test 77s: Check TBF LRU shrinker ============== 11:51:24 (1786377084) [ 7376.353545] Lustre: lustre-OST0000-osc-ffff8b7658650800: disconnect after 21s idle [ 7376.368124] Lustre: Skipped 17 previous similar messages [ 7394.900458] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 11:52:19 (1786377139) [ 7403.237471] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 11:52:27 (1786377147) [ 7420.470093] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 11:52:44 (1786377164) [ 7421.577913] Lustre: DEBUG MARKER: SKIP: sanityn test_80a needs >= 2 MDTs [ 7423.046528] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 11:52:47 (1786377167) [ 7424.309791] Lustre: DEBUG MARKER: SKIP: sanityn test_80b needs >= 2 MDTs [ 7425.822385] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 11:52:50 (1786377170) [ 7427.330292] Lustre: DEBUG MARKER: SKIP: sanityn test_81a needs >= 2 MDTs [ 7428.989929] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 11:52:53 (1786377173) [ 7430.421185] Lustre: DEBUG MARKER: SKIP: sanityn test_81b We need at least 2 MDTs for this test [ 7432.108810] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 11:52:56 (1786377176) [ 7433.440546] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 7435.267275] Lustre: DEBUG MARKER: == sanityn test 81d: parallel rename file cross-dir on same MDT ========================================================== 11:52:59 (1786377179) [ 7549.639816] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 11:54:54 (1786377294) [ 7555.276988] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 11:55:00 (1786377300) [ 7556.777870] Lustre: DEBUG MARKER: SKIP: sanityn test_83 needs >= 2 MDTs [ 7558.328859] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 11:55:03 (1786377303) [ 7569.661246] Lustre: DEBUG MARKER: == sanityn test 85: Lustre API root cache race =========== 11:55:14 (1786377314) [ 7577.618648] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 11:55:22 (1786377322) [ 7578.678178] Lustre: DEBUG MARKER: SKIP: sanityn test_90 needs >= 2 MDTs [ 7579.789129] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 11:55:24 (1786377324) [ 7580.979344] Lustre: DEBUG MARKER: SKIP: sanityn test_91 needs >= 2 MDTs [ 7582.289266] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 11:55:27 (1786377327) [ 7583.629958] Lustre: DEBUG MARKER: SKIP: sanityn test_92 needs >= 2 MDTs [ 7584.899582] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 11:55:29 (1786377329) [ 7598.655245] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 11:55:43 (1786377343) [ 7598.994516] Lustre: DEBUG MARKER: write [ 7599.046770] LustreError: 260656:0:(ldlm_request.c:1533:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 sleeping for 5000ms [ 7601.067058] Lustre: DEBUG MARKER: kill 291002 [ 7601.074754] LustreError: 291002:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 sleeping for 6000ms [ 7604.047630] LustreError: 260656:0:(ldlm_request.c:1533:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 awake [ 7607.111106] LustreError: 291002:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 awake [ 7613.581650] Lustre: DEBUG MARKER: == sanityn test 95a: Check readpage() on a page that was removed from page cache ========================================================== 11:55:58 (1786377358) [ 7616.276102] LustreError: 291608:0:(rw.c:1865:ll_readpage()) cfs_fail_timeout id 1422 sleeping for 10000ms [ 7626.375130] LustreError: 291608:0:(rw.c:1865:ll_readpage()) cfs_fail_timeout id 1422 awake [ 7633.066605] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 11:56:17 (1786377377) [ 7633.436405] LustreError: 292188:0:(rw.c:2112:ll_readpage()) cfs_fail_timeout id 1424 sleeping for 5000ms [ 7635.527148] LustreError: 292188:0:(rw.c:2112:ll_readpage()) cfs_fail_timeout interrupted [ 7644.569495] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 11:56:29 (1786377389) [ 7645.775548] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [ 7647.206051] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 11:56:31 (1786377391) [ 7653.449953] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 11:56:38 (1786377398) [ 7660.066548] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 11:56:44 (1786377404) [ 7665.532868] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 11:56:50 (1786377410) [ 7671.228081] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 11:56:56 (1786377416) [ 7676.704506] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 11:57:01 (1786377421) [ 7682.288913] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 11:57:07 (1786377427) [ 7689.422978] Lustre: DEBUG MARKER: == sanityn test 102: Test open by handle of unlinked file ========================================================== 11:57:14 (1786377434) [ 7695.340250] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 11:57:20 (1786377440) [ 7696.731517] Lustre: *** cfs_fail_loc=415, val=0*** [ 7707.383954] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 11:57:32 (1786377452) [ 7708.782991] Lustre: DEBUG MARKER: SKIP: sanityn test_104 ldiskfs only test [ 7710.184870] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 11:57:34 (1786377454) [ 7710.603770] LustreError: 284867:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 sleeping for 5000ms [ 7715.615281] LustreError: 284867:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 7715.628764] LustreError: 284867:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 2 previous similar messages [ 7725.839946] LustreError: 284867:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 7725.847401] LustreError: 284867:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 4 previous similar messages [ 7736.945847] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 11:58:01 (1786377481) [ 7738.599547] Lustre: DEBUG MARKER: SKIP: sanityn test_106a Test only for ldiskfs and statx() supported [ 7740.043670] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 11:58:04 (1786377484) [ 7745.859815] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 11:58:10 (1786377490) [ 7751.337471] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 11:58:16 (1786377496) [ 7759.254766] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 11:58:24 (1786377504) [ 7770.695542] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 11:58:35 (1786377515) [ 7771.388200] LustreError: 285654:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 sleeping for 4000ms [ 7771.397461] LustreError: 285654:0:(osc_request.c:2989:osc_build_rpc()) Skipped 8 previous similar messages [ 7775.455235] LustreError: 285654:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 awake [ 7775.464085] LustreError: 285654:0:(osc_request.c:2989:osc_build_rpc()) Skipped 1 previous similar message [ 7780.585892] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 11:58:45 (1786377525) [ 7782.614682] Lustre: Unmounted lustre-client [ 7783.864856] Lustre: Unmounted lustre-client [ 7784.898871] Lustre: DEBUG MARKER: Iteration 0 [ 7785.124585] LustreError: 302789:0:(llite_lib.c:1517:ll_fill_super()) cfs_race id 1417 sleeping [ 7785.124699] LustreError: 302788:0:(llite_lib.c:1517:ll_fill_super()) cfs_fail_race id 1417 waking [ 7785.137642] LustreError: 302789:0:(llite_lib.c:1517:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4992 [ 7785.279873] Lustre: Mounted lustre-client - version 2.17.56_50_g6d2b241 [ 7786.308403] Lustre: Unmounted lustre-client [ 7788.719814] Key type lgssc unregistered [ 7788.919920] LNet: 303128:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 7788.932151] LNetError: 303128:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 7788.953989] LNet: Removed LNI 192.168.201.44@tcp [ 7789.538280] Key type .llcrypt unregistered [ 7789.539959] Key type ._llcrypt unregistered [ 7790.344811] Key type ._llcrypt registered [ 7790.348086] Key type .llcrypt registered [ 7790.703746] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 7790.713887] alg: No test for adler32 (adler32-zlib) [ 7791.963600] Lustre: Lustre: Build Version: 2.17.56_50_g6d2b241 [ 7792.592881] LNet: Added LNI 192.168.201.44@tcp [8/256/0/180] [ 7794.311279] Key type lgssc registered [ 7795.568778] Lustre: Echo OBD driver; http://www.lustre.org/ [ 7805.270714] Lustre: DEBUG MARKER: Iteration 1 [ 7805.473030] LustreError: 303950:0:(llite_lib.c:1517:ll_fill_super()) cfs_race id 1417 sleeping [ 7805.473178] LustreError: 303951:0:(llite_lib.c:1517:ll_fill_super()) cfs_fail_race id 1417 waking [ 7805.479232] LustreError: 303950:0:(llite_lib.c:1517:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4997 [ 7806.615281] Lustre: Mounted lustre-client - version 2.17.56_50_g6d2b241 [ 7807.792575] Lustre: Unmounted lustre-client [ 7809.564396] Key type lgssc unregistered [ 7809.737629] LNet: 304294:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 7809.743455] LNetError: 304294:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 7809.769405] LNet: Removed LNI 192.168.201.44@tcp [ 7810.281169] Key type .llcrypt unregistered [ 7810.285787] Key type ._llcrypt unregistered [ 7810.990390] Key type ._llcrypt registered [ 7810.993242] Key type .llcrypt registered [ 7811.309814] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 7811.326120] alg: No test for adler32 (adler32-zlib) [ 7812.279837] Lustre: Lustre: Build Version: 2.17.56_50_g6d2b241 [ 7812.536162] LNet: Added LNI 192.168.201.44@tcp [8/256/0/180] [ 7814.183188] Key type lgssc registered [ 7815.086184] Lustre: Echo OBD driver; http://www.lustre.org/ [ 7823.362680] Lustre: Mounted lustre-client - version 2.17.56_50_g6d2b241 [ 7828.587706] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 11:59:33 (1786377573) [ 7884.767236] Lustre: 305618:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786377575/real 1786377575] req@ffff8b767129e300 x1873152634266880/t0(0) o36->lustre-MDT0000-mdc-ffff8b7660645000@192.168.201.144@tcp:12/10 lens 496/440 e 0 to 1 dl 1786377630 ref 2 fl Rpc:XQr/200/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 7884.795123] Lustre: lustre-MDT0000-mdc-ffff8b7660645000: Connection to lustre-MDT0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 7884.831464] Lustre: lustre-MDT0000-mdc-ffff8b7660645000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 7940.063160] Lustre: 305618:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786377630/real 1786377630] req@ffff8b767129e300 x1873152634266880/t0(0) o36->lustre-MDT0000-mdc-ffff8b7660645000@192.168.201.144@tcp:12/10 lens 496/440 e 0 to 1 dl 1786377685 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 7940.112686] Lustre: lustre-MDT0000-mdc-ffff8b7660645000: Connection to lustre-MDT0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 7940.198328] Lustre: lustre-MDT0000-mdc-ffff8b7660645000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 7995.359870] Lustre: 305618:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786377686/real 1786377686] req@ffff8b767129e300 x1873152634266880/t0(0) o36->lustre-MDT0000-mdc-ffff8b7660645000@192.168.201.144@tcp:12/10 lens 496/440 e 0 to 1 dl 1786377741 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 7995.375338] Lustre: lustre-MDT0000-mdc-ffff8b7660645000: Connection to lustre-MDT0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 7995.431569] Lustre: lustre-MDT0000-mdc-ffff8b7660645000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 7997.593349] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 12:02:21 (1786377741) [ 8000.083882] Lustre: DEBUG MARKER: SKIP: sanityn test_111 needs >= 2 MDTs [ 8002.201787] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 12:02:26 (1786377746) [ 8004.428033] Lustre: DEBUG MARKER: SKIP: sanityn test_112 We need at least 2 MDTs for this test [ 8006.394879] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 12:02:30 (1786377750) [ 8014.156896] Lustre: DEBUG MARKER: == sanityn test 114: implicit default LMV inherit ======== 12:02:38 (1786377758) [ 8016.578962] Lustre: DEBUG MARKER: SKIP: sanityn test_114 We need at least 2 MDTs for this test [ 8018.948463] Lustre: DEBUG MARKER: == sanityn test 115: ldiskfs doesn't check direntry for uniqueness ========================================================== 12:02:42 (1786377762) [ 8020.510601] Lustre: DEBUG MARKER: SKIP: sanityn test_115 ldiskfs only test [ 8022.318304] Lustre: DEBUG MARKER: == sanityn test 116: DNE: Set default LMV layout from a remote client ========================================================== 12:02:46 (1786377766) [ 8024.185812] Lustre: DEBUG MARKER: SKIP: sanityn test_116 needs >= 2 MDTs [ 8026.849747] Lustre: DEBUG MARKER: == sanityn test 121: trunc append race =================== 12:02:51 (1786377771) [ 8027.151618] LustreError: 308298:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 sleeping for 2000ms [ 8029.241358] LustreError: 308298:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 awake [ 8037.497652] Lustre: DEBUG MARKER: == sanityn test 200: service remains healthy while able to process request ========================================================== 12:03:01 (1786377781) [ 8060.767715] Lustre: 304490:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786377790/real 1786377790] req@ffff8b764615e300 x1873152634312064/t0(0) o4->lustre-OST0000-osc-ffff8b7660645000@192.168.201.144@tcp:6/4 lens 4584/448 e 0 to 1 dl 1786377806 ref 2 fl Rpc:XQr/600/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 8060.787822] Lustre: lustre-OST0000-osc-ffff8b7660645000: Connection to lustre-OST0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 8076.255180] Lustre: 304488:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786377806/real 1786377806] req@ffff8b766a369c00 x1873152634313984/t0(0) o4->lustre-OST0000-osc-ffff8b7660645000@192.168.201.144@tcp:6/4 lens 4584/448 e 0 to 1 dl 1786377822 ref 2 fl Rpc:XQr/602/ffffffff rc -11/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 8076.282849] Lustre: 304488:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 8076.291886] Lustre: lustre-OST0000-osc-ffff8b7660645000: Connection to lustre-OST0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 8076.319164] Lustre: lustre-OST0000-osc-ffff8b7660645000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 8092.255781] Lustre: 304488:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786377822/real 1786377822] req@ffff8b766a369c00 x1873152634313984/t0(0) o4->lustre-OST0000-osc-ffff8b7660645000@192.168.201.144@tcp:6/4 lens 4584/448 e 0 to 1 dl 1786377838 ref 2 fl Rpc:XQr/602/ffffffff rc -11/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 8092.286833] Lustre: lustre-OST0000-osc-ffff8b7660645000: Connection to lustre-OST0000 (at 192.168.201.144@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 8092.315982] Lustre: lustre-OST0000-osc-ffff8b7660645000: Connection restored to 192.168.201.144@tcp (at 192.168.201.144@tcp) [ 8120.390609] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff8b7647f1f800.ost_server_uuid 50 [ 8122.076705] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8b7647f1f800.ost_server_uuid in IDLE state after 0 sec [ 8124.140434] Lustre: DEBUG MARKER: cleanup: ====================================================== [ 8125.965410] Lustre: DEBUG MARKER: == sanityn test complete, duration 7824 sec ============== 12:04:30 (1786377870) [ 8127.992964] Lustre: DEBUG MARKER: === sanityn: start cleanup 12:04:32 (1786377872) === [ 8417.859770] Lustre: Unmounted lustre-client [ 8422.412655] Lustre: DEBUG MARKER: === sanityn: finish cleanup 12:09:26 (1786378166) === [ 8425.676860] Lustre: Unmounted lustre-client [ 8450.185241] Key type lgssc unregistered [ 8450.535053] LNet: 311132:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8450.544875] LNetError: 311132:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 8450.555674] LNet: Removed LNI 192.168.201.44@tcp [ 8451.633166] Key type .llcrypt unregistered [ 8451.636979] Key type ._llcrypt unregistered