[ 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-8.fc42 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 439904250 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 0x00000000BFFE2421 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22BD 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 00227D (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2331 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23C1 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE23F9 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22bd-0xbffe2330] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22bc] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2331-0xbffe23c0] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23c1-0xbffe23f8] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe23f9-0xbffe2420] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059618 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829700K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001013] APIC: Switch to symmetric I/O mode setup [ 0.003390] x2apic enabled [ 0.004013] Switched APIC routing to physical x2apic. [ 0.005019] kvm-guest: setup PV IPIs [ 0.008329] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.009000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.009029] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010018] pid_max: default: 32768 minimum: 301 [ 0.011134] LSM: Security Framework initializing [ 0.013054] Yama: becoming mindful. [ 0.014056] SELinux: Initializing. [ 0.015280] *** VALIDATE selinux *** [ 0.025213] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.029788] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.030171] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031133] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.033053] *** VALIDATE tmpfs *** [ 0.034494] *** VALIDATE proc *** [ 0.035262] *** VALIDATE cgroup *** [ 0.036010] *** VALIDATE cgroup2 *** [ 0.037301] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038152] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039011] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.041025] Spectre V2 : User space: Vulnerable [ 0.042007] Speculative Store Bypass: Vulnerable [ 0.045330] debug: unmapping init [mem 0xffffffffb4459000-0xffffffffb4460fff] [ 0.047295] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.048853] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.049030] ... version: 2 [ 0.050012] ... bit width: 48 [ 0.051009] ... generic registers: 4 [ 0.052013] ... value mask: 0000ffffffffffff [ 0.053082] ... max period: 00007fffffffffff [ 0.054017] ... fixed-purpose events: 3 [ 0.055019] ... event mask: 000000070000000f [ 0.057329] rcu: Hierarchical SRCU implementation. [ 0.059670] smp: Bringing up secondary CPUs ... [ 0.060712] x86: Booting SMP configuration: [ 0.061036] .... node #0, CPUs: #1 #2 #3 [ 0.067523] smp: Brought up 1 node, 4 CPUs [ 0.069035] smpboot: Max logical packages: 1 [ 0.070017] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.237511] node 0 deferred pages initialised in 164ms [ 0.242017] devtmpfs: initialized [ 0.243430] x86/mm: Memory block size: 128MB [ 0.249471] gcov: version magic: 0x41383552 [ 0.255151] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.261085] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.269485] pinctrl core: initialized pinctrl subsystem [ 0.271583] [ 0.279017] ************************************************************* [ 0.283016] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.286021] ** ** [ 0.293019] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.296017] ** ** [ 0.299015] ** This means that this kernel is built to expose internal ** [ 0.302019] ** IOMMU data structures, which may compromise security on ** [ 0.305015] ** your system. ** [ 0.307013] ** ** [ 0.312020] ** If you see this message and you are not debugging the ** [ 0.315018] ** kernel, report this immediately to your vendor! ** [ 0.318014] ** ** [ 0.320013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.322015] ************************************************************* [ 0.325531] NET: Registered protocol family 16 [ 0.327471] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.331089] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.334090] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.338171] cpuidle: using governor menu [ 0.340033] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.343795] PCI: Using configuration type 1 for base access [ 0.346291] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.357312] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.358000] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.359196] cryptd: max_cpu_qlen set to 1000 [ 0.361271] ACPI: Added _OSI(Module Device) [ 0.363019] ACPI: Added _OSI(Processor Device) [ 0.365012] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.367014] ACPI: Added _OSI(Processor Aggregator Device) [ 0.373531] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.378429] ACPI: Interpreter enabled [ 0.380176] ACPI: PM: (supports S0 S3 S4 S5) [ 0.382015] ACPI: Using IOAPIC for interrupt routing [ 0.384192] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.388384] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.397986] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.400063] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.404031] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.407090] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.414719] acpiphp: Slot [2] registered [ 0.416159] acpiphp: Slot [5] registered [ 0.418284] acpiphp: Slot [6] registered [ 0.420311] acpiphp: Slot [3] registered [ 0.422146] acpiphp: Slot [4] registered [ 0.424223] acpiphp: Slot [7] registered [ 0.426129] acpiphp: Slot [8] registered [ 0.427137] acpiphp: Slot [9] registered [ 0.428149] acpiphp: Slot [10] registered [ 0.429248] acpiphp: Slot [11] registered [ 0.431129] acpiphp: Slot [12] registered [ 0.433134] acpiphp: Slot [13] registered [ 0.434111] acpiphp: Slot [14] registered [ 0.437126] acpiphp: Slot [15] registered [ 0.438072] acpiphp: Slot [16] registered [ 0.441143] acpiphp: Slot [17] registered [ 0.444369] acpiphp: Slot [18] registered [ 0.445066] acpiphp: Slot [19] registered [ 0.447106] acpiphp: Slot [20] registered [ 0.449112] acpiphp: Slot [21] registered [ 0.451102] acpiphp: Slot [22] registered [ 0.453127] acpiphp: Slot [23] registered [ 0.455103] acpiphp: Slot [24] registered [ 0.457108] acpiphp: Slot [25] registered [ 0.458000] acpiphp: Slot [26] registered [ 0.458000] acpiphp: Slot [27] registered [ 0.461116] acpiphp: Slot [28] registered [ 0.463131] acpiphp: Slot [29] registered [ 0.465082] acpiphp: Slot [30] registered [ 0.466070] acpiphp: Slot [31] registered [ 0.468057] PCI host bridge to bus 0000:00 [ 0.469014] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.472063] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.475032] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.479032] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.480042] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.484031] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.486174] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.490251] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.494301] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.503023] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.508066] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.512022] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.515021] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.517021] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.520692] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.522870] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.526059] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.529846] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.535015] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.546018] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.552014] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.559205] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.567063] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.577018] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.625000] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.640240] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.648069] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.655019] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.683015] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.695529] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.698332] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.700525] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.703091] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.706291] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.710035] iommu: Default domain type: Passthrough [ 0.713467] SCSI subsystem initialized [ 0.728241] ACPI: bus type USB registered [ 0.734084] usbcore: registered new interface driver usbfs [ 0.736092] usbcore: registered new interface driver hub [ 0.739124] usbcore: registered new device driver usb [ 0.743254] pps_core: LinuxPPS API ver. 1 registered [ 0.744017] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.749094] PTP clock support registered [ 0.751252] EDAC MC: Ver: 3.0.0 [ 0.758267] PCI: Using ACPI for IRQ routing [ 0.762148] NetLabel: Initializing [ 0.764012] NetLabel: domain hash size = 128 [ 0.765014] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.767115] NetLabel: unlabeled traffic allowed by default [ 0.769357] vgaarb: loaded [ 0.771501] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.772000] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.776561] clocksource: Switched to clocksource kvm-clock [ 0.915067] VFS: Disk quotas dquot_6.6.0 [ 0.916603] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.918439] *** VALIDATE ramfs *** [ 0.919622] *** VALIDATE hugetlbfs *** [ 0.921233] pnp: PnP ACPI init [ 0.923711] pnp: PnP ACPI: found 6 devices [ 0.937329] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.940531] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.942720] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.945040] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.947528] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.949925] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.952886] NET: Registered protocol family 2 [ 0.955384] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.960178] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.963921] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.969038] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.972259] TCP: Hash tables configured (established 65536 bind 65536) [ 0.975280] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.977701] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.982806] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.986103] NET: Registered protocol family 1 [ 0.989607] RPC: Registered named UNIX socket transport module. [ 0.994073] RPC: Registered udp transport module. [ 0.996933] RPC: Registered tcp transport module. [ 1.000982] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.003861] NET: Registered protocol family 44 [ 1.005935] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.008631] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.011091] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.013970] PCI: CLS 0 bytes, default 64 [ 1.019315] Unpacking initramfs... [ 2.540789] debug: unmapping init [mem 0xffff93653cc64000-0xffff93653ffcffff] [ 2.546405] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.548958] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.552597] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.287633] Initialise system trusted keyrings [ 3.289240] Key type blacklist registered [ 3.290961] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.303148] zbud: loaded [ 3.311468] *** VALIDATE nfs *** [ 3.312495] *** VALIDATE nfs4 *** [ 3.313805] pstore: using deflate compression [ 3.317587] Platform Keyring initialized [ 3.434572] NET: Registered protocol family 38 [ 3.436773] Key type asymmetric registered [ 3.438756] Asymmetric key parser 'x509' registered [ 3.441422] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.444995] io scheduler mq-deadline registered [ 3.447467] io scheduler kyber registered [ 3.449646] io scheduler bfq registered [ 3.451929] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.455753] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.459631] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.462774] ACPI: Power Button [PWRF] [ 3.468179] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.475511] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.496571] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.528263] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.557203] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.562362] Non-volatile memory driver v1.3 [ 3.564204] Linux agpgart interface v0.103 [ 3.599517] virtio_blk virtio1: [vda] 134160 512-byte logical blocks (68.7 MB/65.5 MiB) [ 3.602810] vda: detected capacity change from 0 to 68689920 [ 3.637865] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.641887] vdb: detected capacity change from 0 to 1073741824 [ 3.652783] libphy: Fixed MDIO Bus: probed [ 3.659781] usbcore: registered new interface driver usbserial_generic [ 3.662794] usbserial: USB Serial support registered for generic [ 3.665559] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.707026] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.716871] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.735902] mousedev: PS/2 mouse device common for all mice [ 3.744495] rtc_cmos 00:05: RTC can wake from S4 [ 3.757588] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.758433] rtc_cmos 00:05: registered as rtc0 [ 3.774839] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.782417] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.785588] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.792248] intel_pstate: CPU model not supported [ 3.802293] hid: raw HID events driver (C) Jiri Kosina [ 3.814813] usbcore: registered new interface driver usbhid [ 3.819919] usbhid: USB HID core driver [ 3.823872] drop_monitor: Initializing network drop monitor service [ 3.829033] Initializing XFRM netlink socket [ 3.836579] NET: Registered protocol family 10 [ 3.842781] Segment Routing with IPv6 [ 3.846099] NET: Registered protocol family 17 [ 3.850728] mpls_gso: MPLS GSO support [ 3.877982] RAS: Correctable Errors collector initialized. [ 3.901034] AVX version of gcm_enc/dec engaged. [ 3.922701] AES CTR mode by8 optimization enabled [ 4.171774] sched_clock: Marking stable (4171689763, 0)->(5099210431, -927520668) [ 4.177807] registered taskstats version 1 [ 4.180954] Loading compiled-in X.509 certificates [ 4.184515] zswap: loaded using pool lzo/zbud [ 4.218207] Key type big_key registered [ 4.242674] Key type encrypted registered [ 4.245954] ima: No TPM chip found, activating TPM-bypass! [ 4.249944] ima: Allocated hash algorithm: sha1 [ 4.253276] ima: No architecture policies found [ 4.256271] evm: Initialising EVM extended attributes: [ 4.259546] evm: security.selinux [ 4.261666] evm: security.ima [ 4.263501] evm: security.capability [ 4.265712] evm: HMAC attrs: 0x1 [ 4.269304] rtc_cmos 00:05: setting system clock to 2026-04-11 05:07:19 UTC (1775884039) [ 4.283498] debug: unmapping init [mem 0xffffffffb5403000-0xffffffffb55fffff] [ 4.300605] debug: unmapping init [mem 0xffffffffb4182000-0xffffffffb4458fff] [ 4.322389] Write protecting the kernel read-only data: 28672k [ 4.332532] debug: unmapping init [mem 0xffffffffb2803000-0xffffffffb29fffff] [ 4.341319] debug: unmapping init [mem 0xffffffffb3114000-0xffffffffb31fffff] [ 4.645636] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 4.709414] systemd[1]: Detected virtualization kvm. [ 4.713739] systemd[1]: Detected architecture x86-64. [ 4.716612] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.757084] systemd[1]: No hostname configured. [ 4.759488] systemd[1]: Set hostname to . [ 4.762630] random: systemd: uninitialized urandom read (16 bytes read) [ 4.766065] systemd[1]: Initializing machine ID from random generator. [ 5.107396] random: systemd: uninitialized urandom read (16 bytes read) [ 5.110662] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 5.119481] random: systemd: uninitialized urandom read (16 bytes read) [ 5.158922] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 5.180392] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Swap. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Local File Systems. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... Starting Create Volatile Files and Directories... [ OK ] Started Memstrack Anylazing Service. Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... Starting Journal Service... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 7.164514] device-mapper: uevent: version 1.0.3 [ 7.172369] 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. [ 9.003594] virtio_net virtio0 ens2: renamed from eth0 [ 9.197035] scsi host0: ata_piix [ 9.407443] scsi host1: ata_piix [ 9.409672] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 9.413663] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 14.774444] random: crng init done [ 14.777977] random: 7 urandom warning(s) missed due to ratelimiting [ 15.706067] dracut-initqueue[595]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 16.832602] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Timers. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 20.125775] printk: systemd: 26 output lines suppressed due to ratelimiting [ 20.790303] SELinux: Disabled at runtime. [ 20.950144] 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) [ 20.978893] systemd[1]: Detected virtualization kvm. [ 20.980394] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 23.494123] systemd[1]: initrd-switch-root.service: Succeeded. [ 23.501921] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 23.535286] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 23.542898] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 23.545465] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 23.595521] systemd[1]: Starting Journal Service... Starting Journal Service... [ 23.628907] systemd[1]: Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on RPCbind Server Activation Socket. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Control Socket. Starting Remount Root and Kernel File Systems... Mounting Huge Pages File System... [ OK ] Listening on Process Core Dump Socket. Starting Apply Kernel Variables... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-getty.slice. [ OK ] Listening on initctl Compatibility Named Pipe. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Activating swap /dev/disk/by-label/SWAP... [ OK ] Listening on udev Kernel Socket. Mounting Kernel Debug File System... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ 24.279823] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Stopped target Initrd File Systems. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Created slice User and Session Slice. Starting udev Coldplug all Devices... [ OK ] Reached target Slices. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target RPC Port Mapper. Mounting POSIX Message Queue File System... [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target rpc_pipefs.target. [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted Huge Pages File System. [ OK ] Started Apply Kernel Variables. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started udev Coldplug all Devices. [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 25.384463] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 26.460885] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 26.749218] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 27.040788] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 27.140659] EDAC sbridge: Ver: 1.1.2 [ 30.840317] Key type dns_resolver registered [* ] A start job is running for Configur…-only root support (8s / no limit)[ 31.565527] NFS: Registering the id_resolver key type [ 31.572458] Key type id_resolver registered [ 31.576640] Key type id_legacy registered [** ] 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) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target sshd-keygen.target. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... 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 Login Service. [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started OpenSSH server daemon. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg408-client login: [ 46.938736] hrtimer: interrupt took 3726889 ns [ 91.159695] libcfs: loading out-of-tree module taints kernel. [ 91.224169] Key type ._llcrypt registered [ 91.227450] Key type .llcrypt registered [ 91.759978] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 91.775869] alg: No test for adler32 (adler32-zlib) [ 92.951499] Lustre: Lustre: Build Version: 2.17.52_3_g1a00df9 [ 93.490758] LNet: Added LNI 192.168.204.8@tcp [8/256/0/180] [ 95.159470] Key type lgssc registered [ 96.572212] Lustre: Echo OBD driver; http://www.lustre.org/ [ 212.882372] Lustre: Mounted lustre-client [ 216.738490] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 229.941925] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing check_logdir /tmp/testlogs/ [ 233.249751] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing yml_node [ 236.670808] Lustre: DEBUG MARKER: Client: 2.17.52.3 [ 238.526728] Lustre: DEBUG MARKER: MDS: 2.17.52.3 [ 238.559155] Lustre: lustre-OST0000-osc-ffff93659043c800: disconnect after 23s idle [ 240.318900] Lustre: DEBUG MARKER: OSS: 2.17.52.3 [ 241.267257] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Sat Apr 11 01:11:15 EDT 2026 [ 253.277482] Lustre: DEBUG MARKER: excepting tests: 27 40a [ 254.345661] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 255.542449] Lustre: DEBUG MARKER: === sanityn: start setup 01:11:29 (1775884289) === [ 256.024205] Lustre: Mounted lustre-client [ 258.725266] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing check_config_client /mnt/lustre [ 272.604405] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 276.447818] Lustre: lustre-OST0000-osc-ffff9365a0b50000: disconnect after 20s idle [ 276.451318] Lustre: Skipped 1 previous similar message [ 281.757923] Lustre: DEBUG MARKER: === sanityn: finish setup 01:11:55 (1775884315) === [ 283.351654] Lustre: DEBUG MARKER: == sanityn test 0: do_node_vp() and do_facet_vp() do the right thing ========================================================== 01:11:57 (1775884317) [ 289.247512] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 01:12:03 (1775884323) [ 293.455876] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 01:12:07 (1775884327) [ 297.352711] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 01:12:11 (1775884331) [ 301.592880] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 01:12:15 (1775884335) [ 306.188821] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 01:12:20 (1775884340) [ 311.346961] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 01:12:25 (1775884345) [ 316.057525] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 01:12:30 (1775884350) [ 321.577282] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 01:12:35 (1775884355) [ 326.704786] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 01:12:40 (1775884360) [ 332.042782] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 01:12:46 (1775884366) [ 338.630583] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 01:12:52 (1775884372) [ 342.915884] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 01:12:57 (1775884377) [ 343.008164] Lustre: lustre-OST0001-osc-ffff93659043c800: disconnect after 21s idle [ 343.018576] Lustre: Skipped 1 previous similar message [ 347.699483] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 01:13:01 (1775884381) [ 352.774423] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 01:13:06 (1775884386) [ 353.252499] Lustre: lustre-OST0000-osc-ffff9365a0b50000: disconnect after 20s idle [ 357.310986] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 01:13:11 (1775884391) [ 362.437263] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 01:13:16 (1775884396) [ 366.879823] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 01:13:21 (1775884401) [ 372.678905] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 01:13:26 (1775884406) [ 377.225740] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 01:13:31 (1775884411) [ 382.028508] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 01:13:36 (1775884416) [ 382.487295] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205289279518 file: /mnt/lustre/lockdir/lockfile=144115205289279517 [ 522.437259] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 01:15:56 (1775884556) [ 527.411849] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 01:16:01 (1775884561) [ 531.433863] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 01:16:05 (1775884565) [ 535.369432] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 01:16:09 (1775884569) [ 539.576621] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 01:16:14 (1775884574) [ 544.023853] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 01:16:18 (1775884578) [ 545.185937] Lustre: DEBUG MARKER: chmod [ 549.373419] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 01:16:23 (1775884583) [ 1101.153911] Lustre: DEBUG MARKER: == sanityn test 16a: 2500 iterations of dual-mount fsx === 01:25:35 (1775885135) [ 1198.047454] Lustre: lustre-OST0000-osc-ffff9365a0b50000: disconnect after 20s idle [ 1240.502984] Lustre: DEBUG MARKER: == sanityn test 16b: 2500 iterations of dual-mount fsx at small size ========================================================== 01:27:55 (1775885275) [ 1307.712285] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 01:29:02 (1775885342) [ 1391.656729] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 01:30:26 (1775885426) [ 1408.586285] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 01:30:43 (1775885443) [ 1411.910191] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 01:30:46 (1775885446) [ 1412.418123] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.460418] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.488902] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.529882] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.578200] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.615951] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.648710] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.674632] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.707734] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.762774] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.797710] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.830946] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.866630] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.904147] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.938363] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1412.972336] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.000732] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.034835] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.072322] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.104932] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.135201] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.166803] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.195683] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.225726] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.255784] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.297743] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.349745] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.386139] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.416154] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.447658] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.479098] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.511230] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.543792] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.579217] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.608211] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.641039] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.667147] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.696878] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.728755] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.776135] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.812630] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.850477] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.894537] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.930928] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1413.962912] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.012953] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.044470] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.079299] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.113759] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.154937] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.199281] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.251713] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.281043] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.319398] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.359251] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.401866] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.435660] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.470935] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.517650] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.560560] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.595917] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.634706] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.678610] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.718990] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.756665] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.791659] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.832634] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.863461] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.903386] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.934924] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1414.978330] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.022235] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.054075] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.109257] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.147605] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.195307] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.234825] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.273600] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.321344] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.368043] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.404556] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.453636] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.507208] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.555882] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.600438] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.637447] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.674603] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.725422] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.770303] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.807884] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.838831] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.875970] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.916136] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.948388] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1415.988419] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.034728] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.069506] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.112110] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.153663] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.193231] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.229853] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.268988] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.296777] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.329738] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.364756] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.401505] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.439713] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.486370] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.529796] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.586940] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.636456] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.670904] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.724475] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.764547] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.804561] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.851547] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.882303] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.906782] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.935588] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1416.980051] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.022070] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.052736] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.091067] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.137748] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.186888] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.222204] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.258727] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.291232] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.325612] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.360380] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.394435] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.433693] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.467459] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.512964] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.551909] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.594520] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.630694] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.673969] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.721238] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.770614] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.814248] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.852860] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.883186] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.914473] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1417.964732] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.006658] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.039212] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.088745] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.132563] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.174105] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.224195] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.268597] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.308724] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.339639] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.372032] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.414061] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.445937] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.479907] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.526116] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.566387] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.606574] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.639970] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.671842] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.711847] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.754091] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.790270] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.838076] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.880637] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.918440] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1418.955237] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.007554] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.042218] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.078930] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.116228] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.176993] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.216618] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.260047] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.300887] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.344066] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.378163] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.410260] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.444064] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.482635] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.522066] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.566586] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.610687] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.656678] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.708186] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.743297] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.779365] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.814640] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.853659] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.892581] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.931979] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.961142] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1419.994064] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.038828] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.076349] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.115600] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.155444] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.204637] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.248897] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.285081] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.322512] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.367917] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.407234] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.449260] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.488081] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.526354] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.571639] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.619134] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.660542] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.704807] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.753897] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.795467] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.844923] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.891273] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.938025] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1420.972415] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.006862] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.043116] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.088677] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.132439] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.184190] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.238338] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.301239] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.362281] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.402862] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.442075] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.475317] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.514476] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.551173] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.594213] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.636639] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.684758] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.741656] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.786289] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.821256] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.855816] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.897763] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.929121] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1421.969820] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.010259] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.051388] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.085715] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.127418] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.172126] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.227121] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.282235] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.329904] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.375686] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.413295] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.454812] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.489792] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.529784] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.580605] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.632979] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.677729] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.717966] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.763104] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.805272] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.847827] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.900896] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.948848] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1422.998222] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.046527] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.104928] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.158916] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.217358] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.268829] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.303924] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.346984] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.396757] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.444866] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.491719] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.530672] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.572039] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.617894] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.672987] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.727942] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.769895] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.820836] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.872250] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.923356] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1423.966441] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.015329] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.063479] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.122229] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.171190] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.229197] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.307894] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.367851] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.416823] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.459450] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.520363] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.573336] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.635853] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.701507] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.760678] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.808784] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.860229] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.917141] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.955110] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1424.989847] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.036934] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.086324] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.127228] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.178375] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.222996] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.263525] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.306789] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.358989] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.402310] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.451649] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.501839] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.540569] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.582161] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.648908] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.734659] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.779692] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.834312] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.879389] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.925381] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1425.968116] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.016376] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.057579] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.100408] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.149762] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.203097] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.249770] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.301647] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.344497] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.384459] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.431869] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.476746] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.526262] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.582920] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.655157] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.731253] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.787651] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.831484] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.879858] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.926692] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1426.970879] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.032796] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.086340] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.140453] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.199747] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.269325] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.318859] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.368600] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.409953] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.458315] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.512620] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.576787] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.636164] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.692487] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.754240] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.806747] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.853788] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.909215] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1427.963692] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.001758] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.032276] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.066759] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.120210] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.162660] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.199187] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.251872] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.298099] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.346187] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.389289] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.434385] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.472454] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.516320] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.551815] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.598858] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.639977] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.675128] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.721442] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.757651] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.794103] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.833525] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.881333] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.932110] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1428.976415] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.029285] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.067407] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.103512] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.156847] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.204857] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.239923] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.285131] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.327337] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.365611] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.403910] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.444866] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.492283] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.542740] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.585854] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.636557] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.679459] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.735939] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.798520] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.842413] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.884107] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.929215] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1429.964804] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.002641] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.044734] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.094621] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.130228] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.169209] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.218440] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.270705] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.316682] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.364698] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.404275] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.446581] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.483695] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.532286] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.576350] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.624990] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.668535] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.713400] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.752471] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.787809] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.831293] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.874386] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.909931] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.951961] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1430.989591] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.032771] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.071327] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.116114] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.157659] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.211867] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.248286] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.281205] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.320372] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.368544] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.422493] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.465052] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.505133] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.534520] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.569818] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.610689] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.646456] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.697366] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.749646] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.801103] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.847551] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.890581] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.937480] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1431.969969] rw_seq_cst_vs_d (32365): drop_caches: 3 [ 1433.569107] Lustre: lustre-OST0000-osc-ffff9365a0b50000: disconnect after 24s idle [ 1436.041865] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 01:31:10 (1775885470) [ 1436.243812] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.273741] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.339709] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.431236] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.593774] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.768250] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.846452] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.873104] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.910914] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1436.944152] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.090223] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.112514] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.230531] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.257657] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.351394] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.381581] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.478688] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.509513] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.541065] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.617432] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.652059] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.680861] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1437.773537] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.067972] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.175301] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.209245] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.300302] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.322834] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.358210] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.380654] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.427753] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.467422] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.707640] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.729744] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.788592] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1438.960809] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.072395] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.136140] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.162151] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.211714] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.355940] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.436362] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.458643] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.493784] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.518926] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.542104] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.593193] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.858869] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.887457] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.908946] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.937791] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.963399] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1439.987456] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.234827] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.259762] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.360932] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.398579] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.423507] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.446799] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.474573] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.515188] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.554151] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.573755] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.725951] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.752475] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.841554] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1440.992903] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.038316] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.065916] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.092896] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.204924] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.233152] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.256819] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.291139] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.313272] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.353087] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.376671] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.440393] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.491634] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.524588] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.601519] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.627389] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.654826] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.806465] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.834189] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1441.863139] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.036182] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.168424] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.199830] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.226351] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.385524] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.475303] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.498362] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.519762] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.554502] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.584811] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.612947] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.638284] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.668858] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.699331] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.741619] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.833174] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1442.990917] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.024621] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.051573] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.072641] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.115451] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.146773] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.193042] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.608763] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.637838] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.672935] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.707349] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.736224] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.754990] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.796321] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1443.918966] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.085898] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.457975] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.501889] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.565222] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.658203] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.685812] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.737659] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.807088] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.835386] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.857064] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1444.958910] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.060984] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.097702] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.118269] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.201809] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.380195] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.415941] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.439361] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.488865] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.514605] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.578093] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.649646] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.678373] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1445.738457] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.269668] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.306244] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.383784] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.411850] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.470340] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.537201] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.561844] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.584216] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.700074] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1446.971224] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.087401] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.126571] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.161982] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.248953] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.375378] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.425676] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.524086] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.558622] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.778615] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.801503] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.849147] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.877900] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1447.904802] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.042634] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.079678] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.108579] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.131421] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.176413] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.263758] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.331569] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.356439] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.574411] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.745307] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.772992] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1448.847470] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.061419] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.122275] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.152699] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.239676] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.282447] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.316358] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.342967] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.376430] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.610164] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.644963] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.686830] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.719182] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.835440] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.874225] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.902363] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.933822] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1449.958564] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.053304] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.231100] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.691474] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.738553] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.768826] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.856735] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.899672] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1450.942488] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.003874] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.123978] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.160583] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.257961] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.399421] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.467799] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.512044] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.612785] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.705342] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.749873] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.817589] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.860804] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.888231] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.930576] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1451.963240] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.040798] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.280864] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.318952] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.562483] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.593575] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.625334] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.797816] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.826430] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1452.890972] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.039309] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.111816] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.210326] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.234644] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.257750] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.286426] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.329318] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.428912] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.591768] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.658709] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.683585] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.720216] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1453.927566] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.043425] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.080667] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.110674] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.133736] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.157919] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.189588] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.334165] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.358087] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.571288] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.603620] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.651611] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.678879] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.795836] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1454.920412] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.321427] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.345331] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.386774] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.411940] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.438304] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.465487] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.643244] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.671109] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.715101] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.814464] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.901876] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.935704] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1455.971215] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1456.010220] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1456.032670] rw_seq_cst_vs_d (32946): drop_caches: 3 [ 1459.167855] Lustre: lustre-OST0001-osc-ffff93659043c800: disconnect after 22s idle [ 1459.755957] Lustre: DEBUG MARKER: == sanityn test 16h: mmap read after truncate file ======= 01:31:34 (1775885494) [ 1463.427683] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 01:31:37 (1775885497) [ 1466.974707] Lustre: DEBUG MARKER: == sanityn test 16j: race dio with buffered i/o ========== 01:31:41 (1775885501) [ 1480.859667] Lustre: DEBUG MARKER: == sanityn test 16k: Parallel FSX and drop caches should not panic ========================================================== 01:31:55 (1775885515) [ 1481.045214] bash (35433): drop_caches: 3 [ 1484.142669] bash (35433): drop_caches: 3 [ 1487.230603] bash (35433): drop_caches: 3 [ 1490.603918] bash (35433): drop_caches: 3 [ 1493.783975] bash (35433): drop_caches: 3 [ 1496.876863] bash (35433): drop_caches: 3 [ 1500.753617] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 01:32:15 (1775885535) [ 1507.118882] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 01:32:21 (1775885541) [ 1530.622254] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 01:32:45 (1775885565) [ 1534.982927] Lustre: DEBUG MARKER: loop 5 [ 1537.558992] Lustre: DEBUG MARKER: loop 10 [ 1540.012592] Lustre: DEBUG MARKER: loop 15 [ 1542.819723] Lustre: DEBUG MARKER: loop 20 [ 1546.207163] Lustre: lustre-OST0001-osc-ffff93659043c800: disconnect after 21s idle [ 1546.211535] Lustre: Skipped 1 previous similar message [ 1547.014735] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 01:33:01 (1775885581) [ 1550.845247] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 01:33:05 (1775885585) [ 1553.991485] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 01:33:08 (1775885588) [ 1566.687341] Lustre: lustre-OST0000-osc-ffff9365a0b50000: disconnect after 21s idle [ 1566.690635] Lustre: Skipped 1 previous similar message [ 1576.927192] Lustre: lustre-OST0000-osc-ffff93659043c800: disconnect after 23s idle [ 1576.930954] Lustre: Skipped 2 previous similar messages [ 1618.365768] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 01:34:13 (1775885653) [ 1620.976692] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 01:34:15 (1775885655) [ 1623.451891] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 01:34:18 (1775885658) [ 1626.225445] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 01:34:20 (1775885660) [ 1628.987927] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 01:34:23 (1775885663) [ 1632.542710] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 01:34:27 (1775885667) [ 1636.952769] Lustre: DEBUG MARKER: == sanityn test 26c: set-in-past on open file is not lost on close ========================================================== 01:34:31 (1775885671) [ 1640.330504] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 1640.928224] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 01:34:35 (1775885675) [ 1645.551414] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 01:34:40 (1775885680) [ 1645.687801] Lustre: *** cfs_fail_loc=314, val=0*** [ 1646.330947] Lustre: *** cfs_fail_loc=314, val=0*** [ 1646.332544] Lustre: Skipped 2 previous similar messages [ 1649.346288] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 01:34:43 (1775885683) [ 1654.207280] Lustre: *** cfs_fail_loc=314, val=0*** [ 1654.209204] Lustre: Skipped 1 previous similar message [ 1654.235164] LustreError: lustre-OST0000-osc-ffff9365a0b50000: operation ldlm_enqueue to node 192.168.204.108@tcp failed: rc = -107 [ 1654.239264] Lustre: lustre-OST0000-osc-ffff9365a0b50000: Connection to lustre-OST0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1654.246467] LustreError: lustre-OST0000-osc-ffff9365a0b50000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1654.252483] Lustre: 2426:0:(llite_lib.c:4150:ll_dirty_page_discard_warn()) lustre: dirty page discard: 192.168.204.108@tcp:/lustre/fid: [0x240000403:0x1:0x0]// may get corrupted (rc -108) [ 1654.259793] LustreError: 46321:0:(ldlm_resource.c:1170:ldlm_resource_complain()) lustre-OST0000-osc-ffff9365a0b50000: namespace resource [0x280000401:0x37:0x0].0x0 (ffff936582b71300) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 1654.267063] Lustre: lustre-OST0000-osc-ffff9365a0b50000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 1657.011525] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 01:34:51 (1775885691) [ 1657.082269] LustreError: 46909:0:(file.c:817:ll_intent_file_open()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 1660.103074] LustreError: 46909:0:(file.c:817:ll_intent_file_open()) cfs_fail_timeout id 1419 awake [ 1662.313558] Lustre: DEBUG MARKER: == sanityn test 31s: open should not revalidate invalid dentry ========================================================== 01:34:57 (1775885697) [ 1665.335043] Lustre: DEBUG MARKER: == sanityn test 31t: getattr should not revalidate invalid dentry ========================================================== 01:35:00 (1775885700) [ 1668.838227] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 1669.505658] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 01:35:04 (1775885704) [ 1670.160430] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 1670.830696] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-on-Lock-Cancel ========================================================== 01:35:05 (1775885705) [ 1674.212255] Lustre: lustre-MDT0000-mdc-ffff93659043c800: Connection to lustre-MDT0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1679.329089] LustreError: MGC192.168.204.108@tcp: Connection to MGS (at 192.168.204.108@tcp) was lost; in progress operations using this service will fail [ 1679.334849] Lustre: Evicted from MGS (at 192.168.204.108@tcp) after server handle changed from 0xf99eba5828a635ee to 0xf99eba5828b5a7c8 [ 1679.338988] Lustre: MGC192.168.204.108@tcp: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 1680.647688] Lustre: lustre-MDT0000-mdc-ffff9365a0b50000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 1692.896455] Lustre: DEBUG MARKER: == sanityn test 33d: dependent transactions should trigger COS ========================================================== 01:35:27 (1775885727) [ 1710.047204] Lustre: lustre-OST0000-osc-ffff9365a0b50000: disconnect after 24s idle [ 1713.375433] Lustre: DEBUG MARKER: == sanityn test 33e: independent transactions shouldn't trigger COS ========================================================== 01:35:48 (1775885748) [ 1719.497637] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 01:35:54 (1775885754) [ 1770.425429] Lustre: lustre-OST0001-osc-ffff93659043c800: Connection to lustre-OST0001 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1770.432179] Lustre: Skipped 1 previous similar message [ 1770.437281] LustreError: lustre-OST0001-osc-ffff9365a0b50000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1770.441981] LustreError: lustre-OST0001-osc-ffff93659043c800: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1770.444616] Lustre: lustre-OST0001-osc-ffff9365a0b50000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 1770.451274] Lustre: Skipped 2 previous similar messages [ 1780.665361] Lustre: lustre-OST0000-osc-ffff93659043c800: Connection to lustre-OST0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1780.670653] Lustre: Skipped 1 previous similar message [ 1780.673966] LustreError: lustre-OST0000-osc-ffff93659043c800: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1780.681142] Lustre: lustre-OST0000-osc-ffff93659043c800: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 1791.967215] Lustre: lustre-OST0001-osc-ffff93659043c800: disconnect after 22s idle [ 1791.970723] Lustre: Skipped 1 previous similar message [ 1795.540424] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff93659043c800.ost_server_uuid 50 [ 1796.181778] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93659043c800.ost_server_uuid in FULL state after 0 sec [ 1797.648556] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff93659043c800.ost_server_uuid 50 [ 1798.285913] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93659043c800.ost_server_uuid in IDLE state after 0 sec [ 1800.518825] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff93659043c800.ost_server_uuid 50 [ 1801.147754] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93659043c800.ost_server_uuid in FULL state after 0 sec [ 1802.709714] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff93659043c800.ost_server_uuid 50 [ 1803.351331] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93659043c800.ost_server_uuid in IDLE state after 0 sec [ 1807.485387] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff93659043c800.ost_server_uuid 50 [ 1808.107443] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93659043c800.ost_server_uuid in IDLE state after 0 sec [ 1809.590519] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff93659043c800.ost_server_uuid 50 [ 1810.190700] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93659043c800.ost_server_uuid in IDLE state after 0 sec [ 1810.886727] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 01:37:25 (1775885845) [ 1811.938104] Lustre: DEBUG MARKER: Race attempt 0 [ 1813.618547] Lustre: DEBUG MARKER: Wait for 58249 58379 for 60 sec... [ 1876.604936] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 01:38:31 (1775885911) [ 1882.046887] Lustre: DEBUG MARKER: start test - cycle (0) [ 1898.180200] Lustre: DEBUG MARKER: start test - cycle (1) [ 1918.386140] Lustre: DEBUG MARKER: start test - cycle (2) [ 1938.339810] Lustre: DEBUG MARKER: start test - cycle (3) [ 1958.465273] Lustre: DEBUG MARKER: start test - cycle (4) [ 1974.220876] Lustre: DEBUG MARKER: start test - cycle (5) [ 1990.154674] Lustre: DEBUG MARKER: start test - cycle (6) [ 2010.574030] Lustre: DEBUG MARKER: start test - cycle (7) [ 2024.620468] Lustre: DEBUG MARKER: start test - cycle (8) [ 2040.353519] Lustre: DEBUG MARKER: start test - cycle (9) [ 2056.064737] Lustre: DEBUG MARKER: start test - cycle (10) [ 2073.967581] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 01:41:48 (1775886108) [ 2083.807126] Lustre: lustre-OST0001-osc-ffff9365a0b50000: disconnect after 24s idle [ 2083.810857] Lustre: Skipped 2 previous similar messages [ 2091.615667] Lustre: DEBUG MARKER: == sanityn test 39a: file mtime does not change after rename ========================================================== 01:42:06 (1775886126) [ 2094.165109] Lustre: DEBUG MARKER: == sanityn test 39b: file mtime the same on clients with/out lock ========================================================== 01:42:08 (1775886128) [ 2097.499283] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 01:42:12 (1775886132) [ 2100.599606] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 01:42:15 (1775886135) [ 2100.663479] Lustre: *** cfs_fail_loc=411, val=0*** [ 2102.585032] Lustre: DEBUG MARKER: SKIP: sanityn test_40a skipping ALWAYS excluded test 40a [ 2103.076134] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 01:42:17 (1775886137) [ 2111.075921] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 01:42:25 (1775886145) [ 2119.116083] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 01:42:33 (1775886153) [ 2126.981772] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 01:42:41 (1775886161) [ 2134.351894] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 01:42:49 (1775886169) [ 2139.335906] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 01:42:54 (1775886174) [ 2144.628120] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 01:42:59 (1775886179) [ 2150.025978] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 01:43:04 (1775886184) [ 2155.394866] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 01:43:10 (1775886190) [ 2161.042213] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 01:43:15 (1775886195) [ 2166.642916] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 01:43:21 (1775886201) [ 2171.927071] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 01:43:26 (1775886206) [ 2177.365541] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 01:43:32 (1775886212) [ 2795.487216] Lustre: lustre-OST0000-osc-ffff9365a0b50000: disconnect after 20s idle [ 2795.491434] Lustre: Skipped 4 previous similar messages [ 2893.373377] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 01:55:28 (1775886928) [ 2898.362456] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 01:55:33 (1775886933) [ 2903.423978] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 01:55:38 (1775886938) [ 2908.389063] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 01:55:43 (1775886943) [ 2913.230048] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 01:55:48 (1775886948) [ 2918.185715] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 01:55:52 (1775886952) [ 2923.352566] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 01:55:58 (1775886958) [ 2928.255494] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 01:56:03 (1775886963) [ 2933.381724] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 01:56:08 (1775886968) [ 2956.505926] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 01:56:31 (1775886991) [ 2961.533724] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 01:56:36 (1775886996) [ 2966.367476] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 01:56:41 (1775887001) [ 2971.233566] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 01:56:46 (1775887006) [ 2976.146220] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 01:56:50 (1775887010) [ 2981.070365] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 01:56:55 (1775887015) [ 2986.033753] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 01:57:00 (1775887020) [ 2990.845241] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 01:57:05 (1775887025) [ 2995.689657] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 01:57:10 (1775887030) [ 3031.240462] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 01:57:46 (1775887066) [ 3220.448372] Lustre: lustre-OST0000-osc-ffff93659043c800: disconnect after 24s idle [ 3220.451151] Lustre: Skipped 5 previous similar messages [ 3460.011180] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 02:04:54 (1775887494) [ 3465.113619] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 02:04:59 (1775887499) [ 3470.019382] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 02:05:04 (1775887504) [ 3474.985847] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 02:05:09 (1775887509) [ 3479.882661] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 02:05:14 (1775887514) [ 3484.755883] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 02:05:19 (1775887519) [ 3489.939803] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 02:05:24 (1775887524) [ 3494.913450] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 02:05:29 (1775887529) [ 3499.856171] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 02:05:34 (1775887534) [ 3504.734623] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 02:05:39 (1775887539) [ 3536.534599] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 02:06:11 (1775887571) [ 3541.655667] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 02:06:16 (1775887576) [ 3546.783433] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 02:06:21 (1775887581) [ 3551.870400] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 02:06:26 (1775887586) [ 3556.943011] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 02:06:31 (1775887591) [ 3561.979551] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 02:06:36 (1775887596) [ 3567.108317] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 02:06:41 (1775887601) [ 3571.828542] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 02:06:46 (1775887606) [ 3577.066864] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 02:06:51 (1775887611) [ 4007.390620] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 02:14:02 (1775888042) [ 4012.389372] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 02:14:07 (1775888047) [ 4017.257019] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 02:14:12 (1775888052) [ 4022.100387] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 02:14:16 (1775888056) [ 4027.098743] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 02:14:21 (1775888061) [ 4032.268201] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 02:14:27 (1775888067) [ 4037.580913] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 02:14:32 (1775888072) [ 4042.877802] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 02:14:37 (1775888077) [ 4048.204659] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 02:14:42 (1775888082) [ 4053.228953] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 02:14:48 (1775888088) [ 4058.192254] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 02:14:52 (1775888092) [ 4064.105350] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 02:14:58 (1775888098) [ 4068.892718] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 02:15:03 (1775888103) [ 4073.809734] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 02:15:08 (1775888108) [ 4078.750151] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 02:15:13 (1775888113) [ 4083.673733] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 02:15:18 (1775888118) [ 4089.700551] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 02:15:24 (1775888124) [ 4089.768427] LustreError: 22678:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 sleeping for 2000ms [ 4091.847054] LustreError: 22678:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 awake [ 4096.767372] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 02:15:31 (1775888131) [ 4100.718435] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 02:15:35 (1775888135) [ 4100.788904] LustreError: 240182:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 4104.847128] LustreError: 240182:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 4104.856094] LustreError: 240182:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 4108.919069] LustreError: 240182:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 4108.932726] LustreError: 240189:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 4112.991145] LustreError: 240189:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 4115.146919] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 02:15:49 (1775888149) [ 4121.697064] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 02:15:56 (1775888156) [ 4124.842275] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 02:15:59 (1775888159) [ 4129.035503] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 02:16:03 (1775888163) [ 4136.927189] Lustre: lustre-OST0001-osc-ffff93659043c800: disconnect after 22s idle [ 4136.930780] Lustre: Skipped 2 previous similar messages [ 4153.349553] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 02:16:28 (1775888188) [ 4161.154385] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 02:16:35 (1775888195) [ 4168.746546] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 02:16:43 (1775888203) [ 4181.765396] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 02:16:56 (1775888216) [ 4191.388989] Lustre: DEBUG MARKER: == sanityn test 55e: rename race AB/BA under the same parent dir ========================================================== 02:17:06 (1775888226) [ 4204.289884] Lustre: DEBUG MARKER: == sanityn test 55f: rename: (P1/A -> P2/B) race with (P2/B -> P1/A) ========================================================== 02:17:19 (1775888239) [ 4217.161385] Lustre: DEBUG MARKER: == sanityn test 55g: rename: race with trylock =========== 02:17:31 (1775888251) [ 4231.213646] Lustre: DEBUG MARKER: == sanityn test 56a: test llverdev with single large stripe ========================================================== 02:17:45 (1775888265) [ 4239.033210] Lustre: DEBUG MARKER: == sanityn test 56b: test llverdev and partial verify of wide stripe file ========================================================== 02:17:53 (1775888273) [ 4269.497558] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 02:18:24 (1775888304) [ 4271.871644] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 4274.424317] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 02:18:29 (1775888309) [ 4276.802126] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 02:18:31 (1775888311) [ 4279.092917] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 02:18:33 (1775888313) [ 4281.421262] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 02:18:36 (1775888316) [ 4291.712671] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 02:18:46 (1775888326) [ 4305.304815] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 02:19:00 (1775888340) [ 4307.289491] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 02:19:02 (1775888342) [ 4309.371965] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 02:19:04 (1775888344) [ 4312.457723] LustreError: lustre-MDT0000-mdc-ffff93659043c800: operation ldlm_enqueue to node 192.168.204.108@tcp failed: rc = -35 [ 4315.529286] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 02:19:10 (1775888350) [ 4315.677153] LustreError: 2425:0:(osc_request.c:3140:osc_enqueue_interpret()) cfs_fail_timeout id 31d sleeping for 2000ms [ 4317.759112] LustreError: 2425:0:(osc_request.c:3140:osc_enqueue_interpret()) cfs_fail_timeout id 31d awake [ 4322.692045] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 02:19:17 (1775888357) [ 4371.893925] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 02:20:06 (1775888406) [ 4374.910089] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 02:20:09 (1775888409) [ 4379.143923] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 02:20:13 (1775888413) [ 4384.281592] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 02:20:19 (1775888419) [ 4389.583337] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 02:20:24 (1775888424) [ 4396.953296] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 02:20:31 (1775888431) [ 4404.410085] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 02:20:39 (1775888439) [ 4407.804163] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 02:20:42 (1775888442) [ 4411.519084] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 02:20:46 (1775888446) [ 4418.886322] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 02:20:53 (1775888453) [ 4463.161856] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 02:21:37 (1775888497) [ 4574.863807] Lustre: DEBUG MARKER: == sanityn test 77jb: check TBF-UID/GID NRS policy on files that don't belong to us ========================================================== 02:23:29 (1775888609) [ 4687.410327] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with UID/GID/JobID/OPCode expression ========================================================== 02:25:22 (1775888722) [ 4776.927258] Lustre: lustre-OST0001-osc-ffff93659043c800: disconnect after 22s idle [ 4776.929314] Lustre: Skipped 9 previous similar messages [ 4955.078182] Lustre: DEBUG MARKER: == sanityn test 77kb: Check different granular TBF type combination: jobid+opcode ========================================================== 02:29:49 (1775888989) [ 4981.923456] Lustre: DEBUG MARKER: == sanityn test 77kc: Check different granular TBF type combination: nid+opcode ========================================================== 02:30:16 (1775889016) [ 5011.599704] Lustre: DEBUG MARKER: == sanityn test 77kd: Check different granular TBF type combination: nid+jobid ========================================================== 02:30:46 (1775889046) [ 5032.390624] Lustre: DEBUG MARKER: == sanityn test 77ke: Check different granular TBF type combination: jobid+opcode ========================================================== 02:31:07 (1775889067) [ 5089.194871] Lustre: DEBUG MARKER: == sanityn test 77kf: Check different granular TBF type combination: uid+gid ========================================================== 02:32:03 (1775889123) [ 5145.460520] Lustre: DEBUG MARKER: == sanityn test 77kg: check different granular TBF type combination: uid+opcode ========================================================== 02:33:00 (1775889180) [ 5238.211558] Lustre: DEBUG MARKER: == sanityn test 77kh: Verify that Project ID support for NRS TBF rule ========================================================== 02:34:32 (1775889272) [ 5239.330167] LustreError: 287350:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff93659043c800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 5239.355194] Lustre: Unmounted lustre-client [ 5240.383504] LustreError: 287363:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff9365a0b50000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 5240.386537] LustreError: 287363:0:(lov_obd.c:786:lov_cleanup()) Skipped 1 previous similar message [ 5240.409076] Lustre: Unmounted lustre-client [ 5298.314770] Lustre: Mounted lustre-client [ 5299.793208] Lustre: Mounted lustre-client [ 5300.716386] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5360.496413] Lustre: DEBUG MARKER: == sanityn test 77ki: Add rule with unsupported TBF type should fail for generic TBF ========================================================== 02:36:35 (1775889395) [ 5367.878188] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 02:36:42 (1775889402) [ 5371.076731] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 02:36:45 (1775889405) [ 5421.273065] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 02:37:36 (1775889456) [ 5462.484441] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 02:38:17 (1775889497) [ 5463.519201] Lustre: lustre-OST0001-osc-ffff936591b59000: disconnect after 20s idle [ 5463.522948] Lustre: Skipped 11 previous similar messages [ 5466.520087] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 02:38:21 (1775889501) [ 5502.406851] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 02:38:57 (1775889537) [ 5513.741664] Lustre: DEBUG MARKER: == sanityn test 77r: Change type of tbf policy at run time ========================================================== 02:39:08 (1775889548) [ 5554.625696] Lustre: DEBUG MARKER: == sanityn test 77s: Check TBF LRU shrinker ============== 02:39:49 (1775889589) [ 5565.846238] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 02:40:00 (1775889600) [ 5568.545572] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 02:40:03 (1775889603) [ 5581.010491] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 02:40:15 (1775889615) [ 5584.450769] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 02:40:19 (1775889619) [ 5584.779963] LustreError: 309760:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x2000013a1:0x769:0x0]: rc = -5 [ 5584.784832] LustreError: 309760:0:(llite_lib.c:3705:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5 [ 5585.364161] LustreError: 309811:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x2000013a1:0x775:0x0]: rc = -5 [ 5585.367557] LustreError: 309811:0:(lcommon_cl.c:187:cl_file_inode_init()) Skipped 8 previous similar messages [ 5585.370098] LustreError: 309811:0:(llite_lib.c:3705:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5 [ 5585.373108] LustreError: 309811:0:(llite_lib.c:3705:ll_prep_inode()) Skipped 8 previous similar messages [ 5586.421215] LustreError: 309914:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x240000bd0:0x4e:0x0]: rc = -5 [ 5586.425494] LustreError: 309914:0:(lcommon_cl.c:187:cl_file_inode_init()) Skipped 19 previous similar messages [ 5586.428893] LustreError: 309914:0:(llite_lib.c:3705:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5 [ 5586.432272] LustreError: 309914:0:(llite_lib.c:3705:ll_prep_inode()) Skipped 19 previous similar messages [ 5588.425677] LustreError: 309598:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x240000bd0:0x81:0x0]: rc = -5 [ 5588.430183] LustreError: 309598:0:(lcommon_cl.c:187:cl_file_inode_init()) Skipped 47 previous similar messages [ 5588.433460] LustreError: 309598:0:(llite_lib.c:3705:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5 [ 5588.436816] LustreError: 309598:0:(llite_lib.c:3705:ll_prep_inode()) Skipped 47 previous similar messages [ 5592.467234] LustreError: 310489:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x240000bd0:0xfa:0x0]: rc = -5 [ 5592.470699] LustreError: 310489:0:(lcommon_cl.c:187:cl_file_inode_init()) Skipped 117 previous similar messages [ 5592.473303] LustreError: 310489:0:(llite_lib.c:3705:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5 [ 5592.476238] LustreError: 310489:0:(llite_lib.c:3705:ll_prep_inode()) Skipped 117 previous similar messages [ 5600.537616] LustreError: 311311:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x240000bd0:0x20e:0x0]: rc = -5 [ 5600.542045] LustreError: 311311:0:(lcommon_cl.c:187:cl_file_inode_init()) Skipped 239 previous similar messages [ 5600.545787] LustreError: 311311:0:(llite_lib.c:3705:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5 [ 5600.548752] LustreError: 311311:0:(llite_lib.c:3705:ll_prep_inode()) Skipped 239 previous similar messages [ 5616.653139] LustreError: 312674:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x2000013a1:0xb2d:0x0]: rc = -5 [ 5616.657686] LustreError: 312674:0:(lcommon_cl.c:187:cl_file_inode_init()) Skipped 398 previous similar messages [ 5616.660894] LustreError: 312674:0:(llite_lib.c:3705:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5 [ 5616.663518] LustreError: 312674:0:(llite_lib.c:3705:ll_prep_inode()) Skipped 398 previous similar messages [ 5643.501765] LustreError: 315097:0:(file.c:251:ll_close_inode_openhandle()) lustre-clilmv-ffff9365857d8000: inode [0x2000013a1:0xe04:0x0] mdc close failed: rc = -2 [ 5645.867460] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 02:41:20 (1775889680) [ 5648.006580] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 02:41:22 (1775889682) [ 5689.175863] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 02:42:03 (1775889723) [ 5689.653574] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 5690.199873] Lustre: DEBUG MARKER: == sanityn test 81d: parallel rename file cross-dir on same MDT ========================================================== 02:42:04 (1775889724) [ 5727.054754] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 02:42:41 (1775889761) [ 5729.000313] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 02:42:43 (1775889763) [ 5851.220085] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 02:44:45 (1775889885) [ 5858.513788] Lustre: DEBUG MARKER: == sanityn test 85: Lustre API root cache race =========== 02:44:53 (1775889893) [ 5861.143136] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 02:44:55 (1775889895) [ 6043.124915] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 02:47:57 (1775890077) [ 6211.039130] Lustre: lustre-OST0001-osc-ffff936591b59000: disconnect after 23s idle [ 6211.041177] Lustre: Skipped 6 previous similar messages [ 6225.560140] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 02:51:00 (1775890260) [ 6227.879648] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 02:51:02 (1775890262) [ 6236.764352] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 02:51:11 (1775890271) [ 6236.836669] Lustre: DEBUG MARKER: write [ 6236.855630] LustreError: 289759:0:(ldlm_request.c:1525:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 sleeping for 5000ms [ 6238.859225] Lustre: DEBUG MARKER: kill 377557 [ 6238.861057] LustreError: 377557:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 sleeping for 6000ms [ 6241.959121] LustreError: 289759:0:(ldlm_request.c:1525:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 awake [ 6244.895125] LustreError: 377557:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 awake [ 6247.036484] Lustre: DEBUG MARKER: == sanityn test 95a: Check readpage() on a page that was removed from page cache ========================================================== 02:51:21 (1775890281) [ 6249.203546] LustreError: 378170:0:(rw.c:1868:ll_readpage()) cfs_fail_timeout id 1422 sleeping for 10000ms [ 6259.295103] LustreError: 378170:0:(rw.c:1868:ll_readpage()) cfs_fail_timeout id 1422 awake [ 6261.577817] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 02:51:36 (1775890296) [ 6261.663194] LustreError: 378758:0:(rw.c:2116:ll_readpage()) cfs_fail_timeout id 1424 sleeping for 5000ms [ 6263.743130] LustreError: 378758:0:(rw.c:2116:ll_readpage()) cfs_fail_timeout interrupted [ 6269.716289] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 02:51:44 (1775890304) [ 6270.200041] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [ 6270.739944] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 02:51:45 (1775890305) [ 6273.257869] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 02:51:48 (1775890308) [ 6275.367771] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 02:51:50 (1775890310) [ 6277.429749] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 02:51:52 (1775890312) [ 6279.527446] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 02:51:54 (1775890314) [ 6281.681072] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 02:51:56 (1775890316) [ 6283.842508] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 02:51:58 (1775890318) [ 6286.929520] Lustre: DEBUG MARKER: == sanityn test 102: Test open by handle of unlinked file ========================================================== 02:52:01 (1775890321) [ 6289.763913] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 02:52:04 (1775890324) [ 6290.398148] Lustre: *** cfs_fail_loc=415, val=0*** [ 6296.965690] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 02:52:11 (1775890331) [ 6315.982949] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 02:52:30 (1775890350) [ 6316.070704] LustreError: 289759:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 sleeping for 5000ms [ 6316.074057] LustreError: 289759:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 3 previous similar messages [ 6321.071104] LustreError: 289759:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 6331.271082] LustreError: 289759:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 6331.274509] LustreError: 289759:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 6 previous similar messages [ 6338.656092] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 02:52:53 (1775890373) [ 6341.035758] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 02:52:55 (1775890375) [ 6343.375966] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 02:52:58 (1775890378) [ 6345.725061] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 02:53:00 (1775890380) [ 6350.118336] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 02:53:04 (1775890384) [ 6359.416721] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 02:53:13 (1775890393) [ 6359.663316] LustreError: 389489:0:(osc_request.c:2991:osc_build_rpc()) cfs_fail_timeout id 414 sleeping for 4000ms [ 6359.667168] LustreError: 389489:0:(osc_request.c:2991:osc_build_rpc()) Skipped 6 previous similar messages [ 6363.727157] LustreError: 389489:0:(osc_request.c:2991:osc_build_rpc()) cfs_fail_timeout id 414 awake [ 6363.733900] LustreError: 389489:0:(osc_request.c:2991:osc_build_rpc()) Skipped 2 previous similar messages [ 6366.474629] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 02:53:21 (1775890401) [ 6368.085453] LustreError: 390198:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff936591b59000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6368.088499] LustreError: 390198:0:(lov_obd.c:786:lov_cleanup()) Skipped 1 previous similar message [ 6368.116193] Lustre: Unmounted lustre-client [ 6368.843619] LustreError: 390218:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff9365857d8000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6368.846890] LustreError: 390218:0:(lov_obd.c:786:lov_cleanup()) Skipped 1 previous similar message [ 6368.936131] Lustre: Unmounted lustre-client [ 6369.534541] Lustre: DEBUG MARKER: Iteration 0 [ 6369.666480] LustreError: 390381:0:(llite_lib.c:1369:ll_fill_super()) cfs_race id 1417 sleeping [ 6369.666702] LustreError: 390382:0:(llite_lib.c:1369:ll_fill_super()) cfs_fail_race id 1417 waking [ 6369.671039] LustreError: 390381:0:(llite_lib.c:1369:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4997 [ 6369.736521] Lustre: Mounted lustre-client [ 6370.348255] LustreError: 390495:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff936592221000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6370.353307] LustreError: 390495:0:(lov_obd.c:786:lov_cleanup()) Skipped 1 previous similar message [ 6370.425079] Lustre: Unmounted lustre-client [ 6370.426832] Lustre: Skipped 1 previous similar message [ 6371.460617] Key type lgssc unregistered [ 6371.584427] LNet: 390740:0:(lib-ptl.c:970:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6371.586874] LNetError: 390740:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6371.593734] LNet: Removed LNI 192.168.204.8@tcp [ 6371.912119] Key type .llcrypt unregistered [ 6371.913309] Key type ._llcrypt unregistered [ 6372.315344] Key type ._llcrypt registered [ 6372.316371] Key type .llcrypt registered [ 6372.574915] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 6372.580093] alg: No test for adler32 (adler32-zlib) [ 6373.560300] Lustre: Lustre: Build Version: 2.17.52_3_g1a00df9 [ 6373.827847] LNet: Added LNI 192.168.204.8@tcp [8/256/0/180] [ 6375.431148] Key type lgssc registered [ 6375.968792] Lustre: Echo OBD driver; http://www.lustre.org/ [ 6380.011089] Lustre: DEBUG MARKER: Iteration 1 [ 6380.139994] LustreError: 391571:0:(llite_lib.c:1369:ll_fill_super()) cfs_race id 1417 sleeping [ 6380.140121] LustreError: 391572:0:(llite_lib.c:1369:ll_fill_super()) cfs_fail_race id 1417 waking [ 6380.144650] LustreError: 391571:0:(llite_lib.c:1369:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4998 [ 6381.222361] Lustre: Mounted lustre-client [ 6381.223475] Lustre: Skipped 1 previous similar message [ 6381.767047] LustreError: 391682:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff936590439000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6381.835049] Lustre: Unmounted lustre-client [ 6382.931476] Key type lgssc unregistered [ 6383.062824] LNet: 391927:0:(lib-ptl.c:970:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6383.066050] LNetError: 391927:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6383.076145] LNet: Removed LNI 192.168.204.8@tcp [ 6383.358191] Key type .llcrypt unregistered [ 6383.360177] Key type ._llcrypt unregistered [ 6383.630655] Key type ._llcrypt registered [ 6383.640880] Key type .llcrypt registered [ 6383.892401] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 6383.901461] alg: No test for adler32 (adler32-zlib) [ 6384.812401] Lustre: Lustre: Build Version: 2.17.52_3_g1a00df9 [ 6384.927049] LNet: Added LNI 192.168.204.8@tcp [8/256/0/180] [ 6386.527173] Key type lgssc registered [ 6387.075836] Lustre: Echo OBD driver; http://www.lustre.org/ [ 6391.415332] Lustre: DEBUG MARKER: Iteration 2 [ 6391.543471] LustreError: 392760:0:(llite_lib.c:1369:ll_fill_super()) cfs_race id 1417 sleeping [ 6391.543516] LustreError: 392761:0:(llite_lib.c:1369:ll_fill_super()) cfs_fail_race id 1417 waking [ 6391.549060] LustreError: 392760:0:(llite_lib.c:1369:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4997 [ 6392.612466] Lustre: Mounted lustre-client [ 6392.614050] Lustre: Skipped 1 previous similar message [ 6393.206249] LustreError: 392873:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff936591b58800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6393.211345] LustreError: 392873:0:(lov_obd.c:786:lov_cleanup()) Skipped 2 previous similar messages [ 6393.278829] Lustre: Unmounted lustre-client [ 6394.507442] Key type lgssc unregistered [ 6394.686007] LNet: 393118:0:(lib-ptl.c:970:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6394.691683] LNetError: 393118:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6394.706391] LNet: Removed LNI 192.168.204.8@tcp [ 6395.090210] Key type .llcrypt unregistered [ 6395.092572] Key type ._llcrypt unregistered [ 6395.468780] Key type ._llcrypt registered [ 6395.469953] Key type .llcrypt registered [ 6395.748506] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 6395.753658] alg: No test for adler32 (adler32-zlib) [ 6396.686068] Lustre: Lustre: Build Version: 2.17.52_3_g1a00df9 [ 6396.797708] LNet: Added LNI 192.168.204.8@tcp [8/256/0/180] [ 6398.423264] Key type lgssc registered [ 6399.023920] Lustre: Echo OBD driver; http://www.lustre.org/ [ 6403.801652] Lustre: Mounted lustre-client [ 6406.121587] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 02:54:00 (1775890440) [ 6421.983111] Lustre: 394475:0:(client.c:2482:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775890441/real 1775890441] req@ffff9365b6e50700 x1862156085634944/t0(0) o36->lustre-MDT0000-mdc-ffff9365bbbc0000@192.168.204.108@tcp:12/10 lens 496/440 e 0 to 1 dl 1775890457 ref 2 fl Rpc:XQr/200/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 6421.990222] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection to lustre-MDT0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6422.000969] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 6438.367131] Lustre: 394475:0:(client.c:2482:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775890457/real 1775890457] req@ffff9365b6e50700 x1862156085634944/t0(0) o36->lustre-MDT0000-mdc-ffff9365bbbc0000@192.168.204.108@tcp:12/10 lens 496/440 e 0 to 1 dl 1775890473 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 6438.381776] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection to lustre-MDT0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6438.396570] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 6454.751146] Lustre: 394475:0:(client.c:2482:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775890473/real 1775890473] req@ffff9365b6e50700 x1862156085634944/t0(0) o36->lustre-MDT0000-mdc-ffff9365bbbc0000@192.168.204.108@tcp:12/10 lens 496/440 e 0 to 1 dl 1775890489 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 6454.762614] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection to lustre-MDT0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6454.778908] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 6471.135287] Lustre: 394475:0:(client.c:2482:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775890490/real 1775890490] req@ffff9365b6e50700 x1862156085634944/t0(0) o36->lustre-MDT0000-mdc-ffff9365bbbc0000@192.168.204.108@tcp:12/10 lens 496/440 e 0 to 1 dl 1775890506 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 6471.157645] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection to lustre-MDT0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6471.179808] Lustre: lustre-MDT0000-mdc-ffff9365bbbc0000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 6471.839993] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 02:55:06 (1775890506) [ 6477.991398] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 02:55:12 (1775890512) [ 6481.380306] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 02:55:16 (1775890516) [ 6483.829230] Lustre: DEBUG MARKER: == sanityn test 114: implicit default LMV inherit ======== 02:55:18 (1775890518) [ 6491.165417] Lustre: DEBUG MARKER: == sanityn test 115: ldiskfs doesn't check direntry for uniqueness ========================================================== 02:55:25 (1775890525) [ 6503.500194] Lustre: DEBUG MARKER: == sanityn test 116: DNE: Set default LMV layout from a remote client ========================================================== 02:55:38 (1775890538) [ 6505.765654] Lustre: DEBUG MARKER: == sanityn test 121: trunc append race =================== 02:55:40 (1775890540) [ 6505.834181] LustreError: 399246:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 sleeping for 2000ms [ 6507.919149] LustreError: 399246:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 awake [ 6510.204027] Lustre: DEBUG MARKER: == sanityn test 200: service remains healthy while able to process request ========================================================== 02:55:44 (1775890544) [ 6528.479234] Lustre: 393311:0:(client.c:2482:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775890547/real 1775890547] req@ffff9365be2c1500 x1862156086672640/t0(0) o4->lustre-OST0000-osc-ffff9365bbbc0000@192.168.204.108@tcp:6/4 lens 4584/448 e 0 to 1 dl 1775890563 ref 2 fl Rpc:XQr/600/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 6528.479282] Lustre: lustre-OST0000-osc-ffff9365bbbc0000: Connection to lustre-OST0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6528.492405] Lustre: 393311:0:(client.c:2482:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 6528.501319] Lustre: lustre-OST0000-osc-ffff9365bbbc0000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 6543.839143] Lustre: 393311:0:(client.c:2482:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775890563/real 1775890563] req@ffff9365be2c1500 x1862156086672640/t0(0) o4->lustre-OST0000-osc-ffff9365bbbc0000@192.168.204.108@tcp:6/4 lens 4584/448 e 0 to 1 dl 1775890579 ref 2 fl Rpc:XQr/602/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 6543.839216] Lustre: lustre-OST0000-osc-ffff9365bbbc0000: Connection to lustre-OST0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6543.849642] Lustre: 393311:0:(client.c:2482:ptlrpc_expire_one_request()) Skipped 4 previous similar messages [ 6543.862048] Lustre: lustre-OST0000-osc-ffff9365bbbc0000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 6560.031120] Lustre: 393311:0:(client.c:2482:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1775890579/real 1775890579] req@ffff9365be2c1500 x1862156086672640/t0(0) o4->lustre-OST0000-osc-ffff9365bbbc0000@192.168.204.108@tcp:6/4 lens 4584/448 e 0 to 1 dl 1775890595 ref 2 fl Rpc:XQr/602/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 6560.031164] Lustre: lustre-OST0000-osc-ffff9365bbbc0000: Connection to lustre-OST0000 (at 192.168.204.108@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6560.040936] Lustre: 393311:0:(client.c:2482:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 6560.054067] Lustre: lustre-OST0000-osc-ffff9365bbbc0000: Connection restored to 192.168.204.108@tcp (at 192.168.204.108@tcp) [ 6600.216743] Lustre: DEBUG MARKER: oleg408-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff936598086800.ost_server_uuid 50 [ 6600.714833] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff936598086800.ost_server_uuid in IDLE state after 0 sec [ 6601.288188] Lustre: DEBUG MARKER: cleanup: ====================================================== [ 6602.007251] Lustre: DEBUG MARKER: == sanityn test complete, duration 6360 sec ============== 02:57:16 (1775890636) [ 6602.927361] Lustre: DEBUG MARKER: === sanityn: start cleanup 02:57:17 (1775890637) === [ 6695.424348] LustreError: 401301:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff936598086800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6695.447772] Lustre: Unmounted lustre-client [ 6696.874396] Lustre: DEBUG MARKER: === sanityn: finish cleanup 02:58:51 (1775890731) === [ 6697.231683] LustreError: 401605:0:(lov_obd.c:786:lov_cleanup()) lustre-clilov-ffff9365bbbc0000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 6697.235476] LustreError: 401605:0:(lov_obd.c:786:lov_cleanup()) Skipped 1 previous similar message [ 6697.270977] Lustre: Unmounted lustre-client [ 6735.051949] Key type lgssc unregistered [ 6735.220769] LNet: 402287:0:(lib-ptl.c:970:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6735.228791] LNetError: 402287:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6735.250360] LNet: Removed LNI 192.168.204.8@tcp [ 6735.636226] Key type .llcrypt unregistered [ 6735.638576] Key type ._llcrypt unregistered