[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffd9fff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffda000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 369569040 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2464 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2300 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022C0 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2374 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE2404 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE243C 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2300-0xbffe2373] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22ff] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2374-0xbffe2403] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe2404-0xbffe243b] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe243c-0xbffe2463] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059618 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2895288K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.002288] x2apic enabled [ 0.003005] Switched APIC routing to physical x2apic. [ 0.004010] kvm-guest: setup PV IPIs [ 0.006577] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007017] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008009] pid_max: default: 32768 minimum: 301 [ 0.009118] LSM: Security Framework initializing [ 0.010035] Yama: becoming mindful. [ 0.011023] SELinux: Initializing. [ 0.012067] *** VALIDATE selinux *** [ 0.020123] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024758] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.025145] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027012] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028087] *** VALIDATE tmpfs *** [ 0.030073] *** VALIDATE proc *** [ 0.031191] *** VALIDATE cgroup *** [ 0.032005] *** VALIDATE cgroup2 *** [ 0.033215] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.034120] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.035010] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.036027] Spectre V2 : User space: Vulnerable [ 0.037005] Speculative Store Bypass: Vulnerable [ 0.039968] debug: unmapping init [mem 0xffffffffbca59000-0xffffffffbca60fff] [ 0.041140] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.042727] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.043018] ... version: 2 [ 0.044008] ... bit width: 48 [ 0.045009] ... generic registers: 4 [ 0.046007] ... value mask: 0000ffffffffffff [ 0.047007] ... max period: 00007fffffffffff [ 0.048007] ... fixed-purpose events: 3 [ 0.049009] ... event mask: 000000070000000f [ 0.050252] rcu: Hierarchical SRCU implementation. [ 0.052353] smp: Bringing up secondary CPUs ... [ 0.053449] x86: Booting SMP configuration: [ 0.054011] .... node #0, CPUs: #1 #2 #3 [ 0.056523] smp: Brought up 1 node, 4 CPUs [ 0.057949] smpboot: Max logical packages: 1 [ 0.058012] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.134883] node 0 deferred pages initialised in 75ms [ 0.137302] devtmpfs: initialized [ 0.138306] x86/mm: Memory block size: 128MB [ 0.140899] gcov: version magic: 0x41383552 [ 0.141559] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.142054] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.143194] pinctrl core: initialized pinctrl subsystem [ 0.144133] [ 0.144533] ************************************************************* [ 0.145007] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.146005] ** ** [ 0.147005] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.148005] ** ** [ 0.149006] ** This means that this kernel is built to expose internal ** [ 0.150005] ** IOMMU data structures, which may compromise security on ** [ 0.151005] ** your system. ** [ 0.152005] ** ** [ 0.153008] ** If you see this message and you are not debugging the ** [ 0.154008] ** kernel, report this immediately to your vendor! ** [ 0.155008] ** ** [ 0.156007] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.157008] ************************************************************* [ 0.158573] NET: Registered protocol family 16 [ 0.159356] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.160036] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.161027] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.162294] cpuidle: using governor menu [ 0.163421] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.164344] PCI: Using configuration type 1 for base access [ 0.166084] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.172095] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.173020] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.174165] cryptd: max_cpu_qlen set to 1000 [ 0.176215] ACPI: Added _OSI(Module Device) [ 0.177008] ACPI: Added _OSI(Processor Device) [ 0.177883] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.179009] ACPI: Added _OSI(Processor Aggregator Device) [ 0.182047] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.185418] ACPI: Interpreter enabled [ 0.187055] ACPI: PM: (supports S0 S3 S4 S5) [ 0.189008] ACPI: Using IOAPIC for interrupt routing [ 0.190065] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.193390] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.203130] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.204020] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.206010] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.209060] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.213379] acpiphp: Slot [2] registered [ 0.215343] acpiphp: Slot [5] registered [ 0.216125] acpiphp: Slot [6] registered [ 0.217081] acpiphp: Slot [3] registered [ 0.219078] acpiphp: Slot [4] registered [ 0.220082] acpiphp: Slot [7] registered [ 0.220825] acpiphp: Slot [8] registered [ 0.222041] acpiphp: Slot [9] registered [ 0.222808] acpiphp: Slot [10] registered [ 0.224084] acpiphp: Slot [11] registered [ 0.225070] acpiphp: Slot [12] registered [ 0.227063] acpiphp: Slot [13] registered [ 0.228063] acpiphp: Slot [14] registered [ 0.229065] acpiphp: Slot [15] registered [ 0.231074] acpiphp: Slot [16] registered [ 0.232088] acpiphp: Slot [17] registered [ 0.233073] acpiphp: Slot [18] registered [ 0.235074] acpiphp: Slot [19] registered [ 0.236049] acpiphp: Slot [20] registered [ 0.237052] acpiphp: Slot [21] registered [ 0.238063] acpiphp: Slot [22] registered [ 0.238858] acpiphp: Slot [23] registered [ 0.240079] acpiphp: Slot [24] registered [ 0.241072] acpiphp: Slot [25] registered [ 0.243076] acpiphp: Slot [26] registered [ 0.244061] acpiphp: Slot [27] registered [ 0.245115] acpiphp: Slot [28] registered [ 0.246081] acpiphp: Slot [29] registered [ 0.247068] acpiphp: Slot [30] registered [ 0.249083] acpiphp: Slot [31] registered [ 0.250033] PCI host bridge to bus 0000:00 [ 0.250830] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.252012] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.253043] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.255018] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.257015] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.258019] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.260158] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.261761] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.264960] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.270873] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.274441] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.275011] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.277007] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.278006] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.280387] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.281494] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.283024] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.285519] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.289949] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.296809] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.299901] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.302577] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.307008] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.311009] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.321012] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.329137] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.333956] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.337852] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.344743] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.351573] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.353190] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.355235] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.357200] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.359151] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.362346] iommu: Default domain type: Passthrough [ 0.363361] SCSI subsystem initialized [ 0.365090] ACPI: bus type USB registered [ 0.365974] usbcore: registered new interface driver usbfs [ 0.367033] usbcore: registered new interface driver hub [ 0.369044] usbcore: registered new device driver usb [ 0.370129] pps_core: LinuxPPS API ver. 1 registered [ 0.371005] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.373032] PTP clock support registered [ 0.375078] EDAC MC: Ver: 3.0.0 [ 0.376333] PCI: Using ACPI for IRQ routing [ 0.377483] NetLabel: Initializing [ 0.379006] NetLabel: domain hash size = 128 [ 0.380019] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.381049] NetLabel: unlabeled traffic allowed by default [ 0.382090] vgaarb: loaded [ 0.383247] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.385009] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.390306] clocksource: Switched to clocksource kvm-clock [ 0.473139] VFS: Disk quotas dquot_6.6.0 [ 0.473945] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.475099] *** VALIDATE ramfs *** [ 0.475652] *** VALIDATE hugetlbfs *** [ 0.476348] pnp: PnP ACPI init [ 0.477748] pnp: PnP ACPI: found 6 devices [ 0.488785] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.490407] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.491852] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.493065] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.494333] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.495604] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.497239] NET: Registered protocol family 2 [ 0.498776] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.502216] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.505151] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.508928] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.510978] TCP: Hash tables configured (established 65536 bind 65536) [ 0.513666] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.516141] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.518085] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.519699] NET: Registered protocol family 1 [ 0.521065] RPC: Registered named UNIX socket transport module. [ 0.522522] RPC: Registered udp transport module. [ 0.523844] RPC: Registered tcp transport module. [ 0.525156] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.527363] NET: Registered protocol family 44 [ 0.528394] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.529835] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.531037] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.532761] PCI: CLS 0 bytes, default 64 [ 0.534102] Unpacking initramfs... [ 1.822095] debug: unmapping init [mem 0xffff89a7bcc64000-0xffff89a7bffcffff] [ 1.824121] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 1.825223] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 1.826706] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.269106] Initialise system trusted keyrings [ 2.270301] Key type blacklist registered [ 2.271931] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.279172] zbud: loaded [ 2.282357] *** VALIDATE nfs *** [ 2.283179] *** VALIDATE nfs4 *** [ 2.284190] pstore: using deflate compression [ 2.287936] Platform Keyring initialized [ 2.387035] NET: Registered protocol family 38 [ 2.388275] Key type asymmetric registered [ 2.389473] Asymmetric key parser 'x509' registered [ 2.390814] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.392956] io scheduler mq-deadline registered [ 2.395506] io scheduler kyber registered [ 2.397927] io scheduler bfq registered [ 2.399633] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.402295] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.405127] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.406920] ACPI: Power Button [PWRF] [ 2.412040] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.420021] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.428872] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.454243] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.482366] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.486181] Non-volatile memory driver v1.3 [ 2.487385] Linux agpgart interface v0.103 [ 2.515850] virtio_blk virtio1: [vda] 145784 512-byte logical blocks (74.6 MB/71.2 MiB) [ 2.517909] vda: detected capacity change from 0 to 74641408 [ 2.539820] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 2.542118] vdb: detected capacity change from 0 to 1073741824 [ 2.554449] libphy: Fixed MDIO Bus: probed [ 2.561515] usbcore: registered new interface driver usbserial_generic [ 2.564528] usbserial: USB Serial support registered for generic [ 2.566508] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 2.570259] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 2.572066] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 2.576194] mousedev: PS/2 mouse device common for all mice [ 2.585329] rtc_cmos 00:05: RTC can wake from S4 [ 2.590587] rtc_cmos 00:05: registered as rtc0 [ 2.594210] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 2.596429] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 2.603106] intel_pstate: CPU model not supported [ 2.608901] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 2.613968] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 2.615408] hid: raw HID events driver (C) Jiri Kosina [ 2.620381] usbcore: registered new interface driver usbhid [ 2.622406] usbhid: USB HID core driver [ 2.623856] drop_monitor: Initializing network drop monitor service [ 2.625857] Initializing XFRM netlink socket [ 2.627631] NET: Registered protocol family 10 [ 2.630039] Segment Routing with IPv6 [ 2.631268] NET: Registered protocol family 17 [ 2.632633] mpls_gso: MPLS GSO support [ 2.637683] RAS: Correctable Errors collector initialized. [ 2.639403] AVX version of gcm_enc/dec engaged. [ 2.640489] AES CTR mode by8 optimization enabled [ 2.717852] sched_clock: Marking stable (2717835396, 0)->(3485385054, -767549658) [ 2.720207] registered taskstats version 1 [ 2.722075] Loading compiled-in X.509 certificates [ 2.723986] zswap: loaded using pool lzo/zbud [ 2.753346] Key type big_key registered [ 2.766150] Key type encrypted registered [ 2.767071] ima: No TPM chip found, activating TPM-bypass! [ 2.768822] ima: Allocated hash algorithm: sha1 [ 2.769881] ima: No architecture policies found [ 2.770952] evm: Initialising EVM extended attributes: [ 2.772127] evm: security.selinux [ 2.772893] evm: security.ima [ 2.773763] evm: security.capability [ 2.774670] evm: HMAC attrs: 0x1 [ 2.776490] rtc_cmos 00:05: setting system clock to 2026-07-15 13:25:19 UTC (1784121919) [ 2.780421] debug: unmapping init [mem 0xffffffffbda03000-0xffffffffbdbfffff] [ 2.782191] debug: unmapping init [mem 0xffffffffbc782000-0xffffffffbca58fff] [ 2.789084] Write protecting the kernel read-only data: 28672k [ 2.791591] debug: unmapping init [mem 0xffffffffbae03000-0xffffffffbaffffff] [ 2.793480] debug: unmapping init [mem 0xffffffffbb714000-0xffffffffbb7fffff] [ 2.818679] 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) [ 2.823819] systemd[1]: Detected virtualization kvm. [ 2.825932] systemd[1]: Detected architecture x86-64. [ 2.827944] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 2.851934] systemd[1]: No hostname configured. [ 2.853577] systemd[1]: Set hostname to . [ 2.855370] random: systemd: uninitialized urandom read (16 bytes read) [ 2.857215] systemd[1]: Initializing machine ID from random generator. [ 2.918502] random: ln: uninitialized urandom read (6 bytes read) [ 3.005485] random: systemd: uninitialized urandom read (16 bytes read) [ 3.008122] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 3.013313] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 3.017570] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Timers. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on Journal Socket. [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Sockets. Starting Journal Service... Starting Setup Virtual Console... Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... [ OK ] Reached target Slices. [ OK ] Reached target Swap. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 3.630493] device-mapper: uevent: version 1.0.3 [ 3.632178] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 4.909406] random: fast init done [ 4.914053] virtio_net virtio0 ens2: renamed from eth0 [ 5.037899] scsi host0: ata_piix [ 5.056762] scsi host1: ata_piix [ 5.058651] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 5.061688] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 10.283279] random: crng init done [ 10.284233] random: 7 urandom warning(s) missed due to ratelimiting [ 10.356516] dracut-initqueue[587]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 12.348341] 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 target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. Stopping udev Kernel Device Manager... [ 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 Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 14.681374] printk: systemd: 25 output lines suppressed due to ratelimiting [ 15.280441] SELinux: Disabled at runtime. [ 15.404886] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 15.414782] systemd[1]: Detected virtualization kvm. [ 15.416794] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 16.561283] systemd[1]: initrd-switch-root.service: Succeeded. [ 16.564143] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 16.569936] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 16.573279] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 16.575845] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 16.587615] systemd[1]: Starting Journal Service... Starting Journal Service... [ 16.598631] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ OK ] Listening on udev Control Socket. [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting Huge Pages File System... [ OK ] Created slice system-getty.slice. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. Starting Apply Kernel Variables... [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice User and Session Slice. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target rpc_pipefs.target. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Starting udev Coldplug all Devices... [ OK ] Created slice system-sshd\x2dkeygen.slice. Mounting Kernel Debug File System... Activating swap /dev/disk/by-label/SWAP... Mounting POSIX Message Queue File System... [ OK ] Reached target Slices. [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. [ 17.352534] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Flush Journal to Persistent Storage... Starting Create Static Device Nodes in /dev... [ OK ] Started udev Coldplug all Devices. [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 17.911619] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 18.866936] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 18.935120] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 19.352457] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 19.433087] EDAC sbridge: Ver: 1.1.2 [ 21.614768] Key type dns_resolver registered [ 21.999206] NFS: Registering the id_resolver key type [ 22.000898] Key type id_resolver registered [ 22.003568] Key type id_legacy registered [ 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 Create Volatile Files and Directories. [ OK ] Started Load/Save Random Seed. 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 Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting Hostname Service... [ OK ] Started Login Service. [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg217-client login: [ 66.738709] libcfs: loading out-of-tree module taints kernel. [ 66.769672] Key type ._llcrypt registered [ 66.771277] Key type .llcrypt registered [ 67.071077] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 67.079297] alg: No test for adler32 (adler32-zlib) [ 68.137883] Lustre: Lustre: Build Version: 2.17.54_162_g38d062c [ 68.488260] LNet: Added LNI 192.168.202.17@tcp [8/256/0/180] [ 70.111153] Key type lgssc registered [ 70.788512] Lustre: Echo OBD driver; http://www.lustre.org/ [ 120.664975] Lustre: Mounted lustre-client [ 123.151389] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 132.377727] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing check_logdir /tmp/testlogs/ [ 134.193073] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing yml_node [ 136.142293] Lustre: DEBUG MARKER: Client: 2.17.54.162 [ 137.292612] Lustre: DEBUG MARKER: MDS: 2.17.54.162 [ 138.358794] Lustre: DEBUG MARKER: OSS: 2.17.54.162 [ 139.074223] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Wed Jul 15 09:27:35 EDT 2026 [ 141.279287] Lustre: lustre-OST0000-osc-ffff89a803b46000: disconnect after 20s idle [ 145.743266] Lustre: DEBUG MARKER: excepting tests: 27 40a [ 146.282422] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 146.903821] Lustre: DEBUG MARKER: === sanityn: start setup 09:27:43 (1784122063) === [ 147.156605] Lustre: Mounted lustre-client [ 149.184294] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing check_config_client /mnt/lustre [ 155.489265] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 159.491308] Lustre: DEBUG MARKER: === sanityn: finish setup 09:27:55 (1784122075) === [ 160.286293] Lustre: DEBUG MARKER: == sanityn test 0: do_node_vp() and do_facet_vp() do the right thing ========================================================== 09:27:56 (1784122076) [ 163.275755] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 09:27:59 (1784122079) [ 165.211918] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 09:28:01 (1784122081) [ 167.184897] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 09:28:03 (1784122083) [ 169.154645] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 09:28:05 (1784122085) [ 171.186470] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 09:28:07 (1784122087) [ 173.202052] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 09:28:09 (1784122089) [ 175.560582] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 09:28:11 (1784122091) [ 176.075397] Lustre: DEBUG MARKER: SKIP: sanityn test_2f needs >= 2 MDTs [ 176.642540] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 09:28:12 (1784122092) [ 178.959617] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 09:28:15 (1784122095) [ 181.051312] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 09:28:17 (1784122097) [ 184.361941] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 09:28:20 (1784122100) [ 186.706857] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 09:28:22 (1784122102) [ 189.028688] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 09:28:25 (1784122105) [ 191.452605] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 09:28:27 (1784122107) [ 193.822690] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 09:28:30 (1784122110) [ 196.564489] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 09:28:32 (1784122112) [ 199.538178] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 09:28:35 (1784122115) [ 202.611732] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 09:28:38 (1784122118) [ 205.229994] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 09:28:41 (1784122121) [ 207.928451] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 09:28:44 (1784122124) [ 208.070885] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205272502304 file: /mnt/lustre/lockdir/lockfile=144115205272502302 [ 382.509086] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 09:31:38 (1784122298) [ 387.905573] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 09:31:43 (1784122303) [ 391.506579] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 09:31:47 (1784122307) [ 395.159515] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 09:31:50 (1784122310) [ 398.830480] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 09:31:54 (1784122314) [ 402.422491] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 09:31:58 (1784122318) [ 403.427442] Lustre: DEBUG MARKER: chmod [ 406.810373] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 09:32:02 (1784122322) [ 431.034361] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7527424KB free > 800000KB, increase MAXFREE (or reduce fs size) [ 441.572589] Lustre: DEBUG MARKER: == sanityn test 16a: 500 iterations of dual-mount fsx ==== 09:32:37 (1784122357) [ 464.817567] Lustre: DEBUG MARKER: == sanityn test 16b: 500 iterations of dual-mount fsx at small size ========================================================== 09:33:00 (1784122380) [ 476.092213] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 09:33:12 (1784122392) [ 477.210886] Lustre: DEBUG MARKER: SKIP: sanityn test_16c dio on ldiskfs only [ 478.042740] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 09:33:14 (1784122394) [ 499.026433] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 09:33:35 (1784122415) [ 502.279879] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 09:33:38 (1784122418) [ 502.811484] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 502.844702] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 502.878445] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 502.908659] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 502.942686] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 502.966512] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 502.989074] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.020160] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.046676] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.075754] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.102309] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.125815] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.156413] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.192654] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.223056] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.262245] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.301830] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.332713] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.355833] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.385400] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.423349] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.455580] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.490533] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.528299] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.554100] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.580926] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.612810] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.655938] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.690051] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.720515] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.747558] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.776712] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.812518] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.844729] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.884325] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.938679] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 503.976887] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.008607] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.047565] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.098625] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.139181] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.185129] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.230695] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.268984] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.311288] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.346233] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.379989] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.408062] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.437705] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.476195] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.521450] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.571143] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.601868] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.644215] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.686372] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.715407] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.755913] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.780601] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.808774] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.831930] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.855778] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.880156] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.913218] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.935270] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.962208] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 504.988446] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.025176] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.056755] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.095661] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.143095] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.181160] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.212580] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.241575] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.281104] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.308642] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.332672] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.360311] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.403837] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.454668] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.517389] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.573239] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.621099] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.661056] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.711748] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.777931] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.832333] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.866578] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.895939] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.946238] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 505.984297] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.025086] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.078346] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.132231] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.181854] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.220270] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.266782] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.322741] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.381307] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.450950] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.493504] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.538175] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.587681] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.630060] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.656593] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.687819] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.716947] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.772175] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.816504] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.853552] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.913689] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.957406] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 506.985932] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.044291] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.087717] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.137682] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.194482] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.248554] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.285049] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.331457] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.375547] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.422959] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.467249] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.527692] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.556748] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.593835] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.636586] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.668110] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.713214] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.758323] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.816896] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.863624] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.910531] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.940115] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 507.966255] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.009234] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.060981] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.106340] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.140669] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.188216] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.228206] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.266824] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.297743] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.333117] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.362085] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.405586] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.442729] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.482476] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.526513] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.564509] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.620298] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.667082] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.709800] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.753127] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.810265] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.869429] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.914632] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 508.959790] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.005827] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.053673] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.108047] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.170811] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.230834] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.285545] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.334570] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.387662] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.430359] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.479295] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.518601] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.556649] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.596055] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.645665] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.701544] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.752903] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.807396] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.843240] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.879838] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.910947] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.953605] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 509.997169] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.039058] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.076110] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.110599] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.149596] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.178160] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.221085] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.244977] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.269594] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.295046] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.336400] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.381748] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.416342] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.452862] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.499586] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.544985] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.598653] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.638691] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.683095] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.737822] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.776432] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.819582] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.862688] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.896593] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.921350] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.947104] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 510.981861] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.015075] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.040607] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.068821] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.100181] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.169849] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.216679] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.246037] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.283091] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.319813] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.352641] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.393807] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.428120] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.455853] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.490693] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.532703] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.573262] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.614472] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.650724] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.678635] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.707535] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.757423] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.808528] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.843678] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.874138] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.904822] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.946759] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 511.986883] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.031434] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.067839] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.096443] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.139522] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.188554] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.242162] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.287528] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.327463] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.368777] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.412933] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.454207] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.485692] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.539629] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.587812] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.627514] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.672341] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.715340] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.757635] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.796097] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.841879] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.876539] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.923764] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 512.965494] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.004645] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.040024] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.083975] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.137707] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.183767] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.218502] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.254367] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.291823] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.338531] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.385469] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.413192] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.441220] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.475400] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.510092] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.553683] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.595620] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.622198] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.660712] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.697666] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.734359] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.783164] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.819819] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.870491] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.920730] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 513.986411] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.033737] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.090351] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.150105] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.214858] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.250720] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.277227] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.313854] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.346387] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.385470] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.418928] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.456344] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.485346] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.521240] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.557549] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.600149] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.662201] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.717258] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.756905] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.788843] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.833601] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.868863] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.913667] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.940122] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 514.968852] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.012642] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.040879] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.069898] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.101732] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.132604] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.168531] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.209721] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.256668] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.304707] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.340781] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.368546] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.408966] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.452573] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.480442] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.514655] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.545041] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.576669] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.625935] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.656589] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.685784] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.719957] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.752431] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.784898] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.817175] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.866674] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.905108] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.938549] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 515.978624] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.028386] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.075703] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.108602] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.141909] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.180451] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.237126] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.286235] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.337716] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.387973] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.431879] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.471385] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.522316] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.574188] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.631776] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.714358] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.779491] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.838101] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.885075] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.922311] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 516.955249] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.004437] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.054812] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.115481] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.163873] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.235424] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.304505] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.349483] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.393263] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.422965] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.472187] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.516858] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.567834] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.617479] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.657469] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.713959] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.759640] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.809401] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.859168] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.913221] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 517.960756] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.011226] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.064613] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.123481] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.205839] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.269642] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.320381] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.351887] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.397591] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.445115] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.492188] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.542766] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.587938] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.627241] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.656061] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.700522] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.741479] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.780176] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.813629] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.851234] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.894946] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 518.934331] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.009749] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.097486] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.144275] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.205021] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.249501] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.293477] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.343507] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.397805] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.441482] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.485946] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.533467] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.587606] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.626447] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.666349] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.719542] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.777878] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.826447] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.862060] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.915185] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 519.960785] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.005715] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.041776] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.091782] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.128817] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.161129] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.232276] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.274737] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.313001] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.351948] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.384287] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.429166] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.466706] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.501783] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.528776] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.575953] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.608693] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.652509] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.690735] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.735507] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.792054] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.835852] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.882339] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 520.949085] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.019312] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.061821] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.107610] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.157169] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.184229] Lustre: lustre-OST0001-osc-ffff89a81800a000: disconnect after 21s idle [ 521.186739] Lustre: Skipped 1 previous similar message [ 521.190482] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.245730] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.311762] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.374593] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.449572] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.517417] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.569135] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.607378] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.651845] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.692638] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.734308] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.785517] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.858545] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.903045] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.933386] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.964071] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 521.987786] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.011560] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.051514] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.090150] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.130167] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.170277] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.210983] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.256751] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.312194] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.370985] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 522.417555] rw_seq_cst_vs_d (29581): drop_caches: 3 [ 526.253207] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 09:34:02 (1784122442) [ 526.303510] Lustre: lustre-OST0001-osc-ffff89a803b46000: disconnect after 22s idle [ 526.533479] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 526.585239] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 526.681641] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 526.699316] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 526.856188] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 526.938383] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.077981] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.105045] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.130276] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.180134] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.215195] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.290104] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.321680] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.348122] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.412975] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.472947] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.491740] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.548170] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.604457] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.638590] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.796431] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.866225] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.890110] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 527.981510] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 528.606355] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 528.674701] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 528.691995] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 528.710466] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 528.734307] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 528.752333] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 528.893436] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.044972] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.082565] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.102079] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.141249] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.161670] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.195811] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.237134] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.256239] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.280649] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.399294] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.423172] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.440432] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.455708] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.497319] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.522261] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.543691] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.681881] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.719140] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.778230] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.843729] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.877402] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.901617] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 529.998520] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.082625] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.215744] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.238654] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.312391] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.412648] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.493849] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.550578] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.576182] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.684959] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.703146] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.724831] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.745504] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.838849] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 530.886766] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.098838] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.296877] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.329777] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.459741] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.525743] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.612641] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.643556] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.667515] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.753058] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.898903] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.956931] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 531.979169] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.003033] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.023071] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.040208] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.374712] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.539612] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.560857] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.689811] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.772685] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.791372] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.898181] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 532.985552] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.054250] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.094180] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.198986] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.349742] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.582879] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.635329] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.661472] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.750524] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.766645] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.787906] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.812532] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.831229] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.955507] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 533.992207] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.011776] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.055651] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.075602] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.140905] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.158924] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.288110] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.331072] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.414941] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.510563] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.535805] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.614781] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 534.694384] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.020039] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.036112] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.205655] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.296741] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.330876] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.349568] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.419395] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.738605] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.783874] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.912614] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 535.938228] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.095073] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.161142] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.255180] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.295172] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.331146] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.355226] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.548526] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.605572] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.628066] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.732750] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.754942] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.784921] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.908266] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 536.948126] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.051295] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.104493] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.127872] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.162914] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.213500] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.349932] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.387212] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.540588] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.577585] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.678276] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.703468] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.747406] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.836698] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.862975] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.923263] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.946542] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 537.987818] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.005590] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.023868] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.051182] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.092421] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.112903] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.141988] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.207816] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.348509] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.373186] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.402338] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.452517] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.503760] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.543856] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.566206] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.586179] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.605793] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.722925] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.756939] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.798348] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.883344] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.904626] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.923713] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.940676] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 538.987385] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.004980] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.122843] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.147374] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.174668] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.250389] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.281680] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.301492] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.344541] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.371353] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.400395] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.442280] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.462169] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.481888] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.572825] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.629111] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.650567] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.792562] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.832597] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.915346] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.932629] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 539.957717] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.026348] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.043970] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.067865] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.207192] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.240398] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.331715] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.357954] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.377947] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.407759] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.529897] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.621471] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.648136] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.813235] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.851236] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.893658] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 540.928696] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.000527] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.049793] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.095212] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.175922] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.202497] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.221427] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.253184] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.371431] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.390644] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.449511] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.591864] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.611644] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.644113] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.681943] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.711130] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.734053] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.754233] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.839792] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.857049] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.872813] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.927462] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 541.954685] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.092987] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.142814] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.234133] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.258758] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.295968] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.320831] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.343343] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.463748] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.545188] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.571494] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.691276] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.775641] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.863088] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 542.906697] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.104691] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.125352] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.294570] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.335032] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.353294] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.472170] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.514636] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.555609] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.594711] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.634811] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.656465] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.686194] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.755133] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.776681] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.795749] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.854544] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.901592] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 543.973075] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.007407] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.040332] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.217646] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.247848] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.272153] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.340386] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.518142] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.542340] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.565855] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.586369] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.604136] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.647940] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.666101] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.680939] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.764865] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.891995] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.918278] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 544.937862] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.032679] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.072644] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.121864] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.140739] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.189524] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.245826] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.269598] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.305675] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.339609] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.438392] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.509520] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.532253] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.553748] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.570783] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.600693] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.615445] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.644262] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.727183] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.746431] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.769067] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.803869] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.823974] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.884937] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.949094] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.966346] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 545.984397] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.055830] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.078765] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.129738] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.171446] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.190064] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.209393] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.242846] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.279722] rw_seq_cst_vs_d (30153): drop_caches: 3 [ 546.783140] Lustre: lustre-OST0000-osc-ffff89a803b46000: disconnect after 22s idle [ 549.581289] Lustre: DEBUG MARKER: == sanityn test 16h: mmap read after truncate file ======= 09:34:25 (1784122465) [ 552.698323] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 09:34:28 (1784122468) [ 555.979290] Lustre: DEBUG MARKER: == sanityn test 16j: race dio with buffered i/o ========== 09:34:31 (1784122471) [ 574.988580] Lustre: DEBUG MARKER: == sanityn test 16k: Parallel FSX and drop caches should not panic ========================================================== 09:34:51 (1784122491) [ 575.204916] bash (32601): drop_caches: 3 [ 578.346698] bash (32601): drop_caches: 3 [ 581.734758] bash (32601): drop_caches: 3 [ 584.817940] bash (32601): drop_caches: 3 [ 587.912375] bash (32601): drop_caches: 3 [ 591.015904] bash (32601): drop_caches: 3 [ 594.127227] bash (32601): drop_caches: 3 [ 597.197841] bash (32601): drop_caches: 3 [ 600.858931] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 09:35:17 (1784122517) [ 604.583116] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 09:35:20 (1784122520) [ 713.025173] LustreError: lustre-OST0001-osc-ffff89a803b46000: operation ost_write to node 192.168.202.117@tcp failed: rc = -107 [ 713.029993] Lustre: lustre-OST0001-osc-ffff89a803b46000: Connection to lustre-OST0001 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 713.042212] LustreError: lustre-OST0001-osc-ffff89a803b46000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 713.048542] Lustre: 2359:0:(llite_lib.c:4327:ll_dirty_page_discard_warn()) lustre: dirty page discard: 192.168.202.117@tcp:/lustre/fid: [0x200000401:0x6e:0x0]// may get corrupted (rc -5) [ 713.055149] Lustre: lustre-OST0001-osc-ffff89a803b46000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 713.060615] LustreError: lustre-OST0000-osc-ffff89a81800a000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 713.066278] Lustre: 2360:0:(llite_lib.c:4327:ll_dirty_page_discard_warn()) lustre: dirty page discard: 192.168.202.117@tcp:/lustre/fid: [0x200000401:0x6d:0x0]// may get corrupted (rc -5) [ 721.203140] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 09:37:17 (1784122637) [ 722.315542] Lustre: DEBUG MARKER: SKIP: sanityn test_19 not cache-capable obdfilter [ 722.933315] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 09:37:19 (1784122639) [ 726.043583] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 09:37:22 (1784122642) [ 728.673493] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 09:37:24 (1784122644) [ 736.223249] Lustre: lustre-OST0001-osc-ffff89a81800a000: disconnect after 20s idle [ 736.226052] Lustre: Skipped 1 previous similar message [ 746.463263] Lustre: lustre-OST0000-osc-ffff89a803b46000: disconnect after 24s idle [ 793.024813] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 09:38:29 (1784122709) [ 795.684524] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 09:38:31 (1784122711) [ 798.011274] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 09:38:34 (1784122714) [ 800.532159] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 09:38:36 (1784122716) [ 801.122081] Lustre: DEBUG MARKER: SKIP: sanityn test_25b needs >= 2 MDTs [ 801.763556] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 09:38:37 (1784122717) [ 805.283950] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 09:38:41 (1784122721) [ 810.204589] Lustre: DEBUG MARKER: == sanityn test 26c: set-in-past on open file is not lost on close ========================================================== 09:38:46 (1784122726) [ 813.704711] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 814.281112] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 09:38:50 (1784122730) [ 818.809871] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 09:38:55 (1784122735) [ 818.913573] Lustre: *** cfs_fail_loc=314, val=0*** [ 819.935346] Lustre: *** cfs_fail_loc=314, val=0*** [ 819.937292] Lustre: Skipped 3 previous similar messages [ 821.977247] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 09:38:58 (1784122738) [ 838.094503] Lustre: *** cfs_fail_loc=314, val=0*** [ 841.077029] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 09:39:17 (1784122757) [ 841.236170] LustreError: 42546:0:(file.c:818:ll_intent_file_open()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 842.262309] LustreError: lustre-OST0000-osc-ffff89a81800a000: operation ldlm_enqueue to node 192.168.202.117@tcp failed: rc = -107 [ 842.268022] LustreError: Skipped 1 previous similar message [ 842.270485] Lustre: lustre-OST0000-osc-ffff89a81800a000: Connection to lustre-OST0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 842.280193] Lustre: Skipped 1 previous similar message [ 842.285437] LustreError: lustre-OST0000-osc-ffff89a81800a000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 842.292183] Lustre: 2359:0:(llite_lib.c:4327:ll_dirty_page_discard_warn()) lustre: dirty page discard: 192.168.202.117@tcp:/lustre/fid: [0x200000402:0x25:0x0]// may get corrupted (rc -108) [ 842.301942] Lustre: lustre-OST0000-osc-ffff89a81800a000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 842.304503] Lustre: Skipped 1 previous similar message [ 844.255115] LustreError: 42546:0:(file.c:818:ll_intent_file_open()) cfs_fail_timeout id 1419 awake [ 846.688371] Lustre: DEBUG MARKER: == sanityn test 31s: open should not revalidate invalid dentry ========================================================== 09:39:22 (1784122762) [ 849.913614] Lustre: DEBUG MARKER: == sanityn test 31t: getattr should not revalidate invalid dentry ========================================================== 09:39:26 (1784122766) [ 853.289593] Lustre: DEBUG MARKER: == sanityn test 32b: lockless i/o ======================== 09:39:29 (1784122769) [ 853.945699] Lustre: DEBUG MARKER: SKIP: sanityn test_32b max_nolock_bytes is removed >= 2.17.53 [ 854.528314] Lustre: DEBUG MARKER: == sanityn test 32c: contention detection ================ 09:39:30 (1784122770) [ 863.794042] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 864.335547] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 09:39:40 (1784122780) [ 864.945435] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 865.612292] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-on-Lock-Cancel ========================================================== 09:39:41 (1784122781) [ 866.186464] Lustre: DEBUG MARKER: SKIP: sanityn test_33c needs >= 2 MDTs [ 866.754770] Lustre: DEBUG MARKER: == sanityn test 33d: dependent transactions should trigger COS ========================================================== 09:39:42 (1784122782) [ 867.322475] Lustre: DEBUG MARKER: SKIP: sanityn test_33d needs >= 2 MDTs [ 867.953517] Lustre: DEBUG MARKER: == sanityn test 33e: independent transactions shouldn't trigger COS ========================================================== 09:39:44 (1784122784) [ 868.525401] Lustre: DEBUG MARKER: SKIP: sanityn test_33e needs >= 2 MDTs [ 869.146851] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 09:39:45 (1784122785) [ 879.583235] Lustre: lustre-OST0001-osc-ffff89a81800a000: disconnect after 20s idle [ 879.585711] Lustre: Skipped 2 previous similar messages [ 914.361620] Lustre: lustre-OST0001-osc-ffff89a803b46000: Connection to lustre-OST0001 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 914.368724] LustreError: lustre-OST0001-osc-ffff89a81800a000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 914.373827] LustreError: lustre-OST0001-osc-ffff89a803b46000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 914.374107] Lustre: lustre-OST0001-osc-ffff89a81800a000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 930.785699] Lustre: lustre-OST0000-osc-ffff89a803b46000: Connection to lustre-OST0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 930.790613] Lustre: Skipped 1 previous similar message [ 930.793749] LustreError: lustre-OST0000-osc-ffff89a803b46000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 930.799809] Lustre: lustre-OST0000-osc-ffff89a803b46000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 930.803254] Lustre: Skipped 1 previous similar message [ 935.903254] Lustre: lustre-OST0001-osc-ffff89a803b46000: disconnect after 21s idle [ 935.906370] Lustre: Skipped 2 previous similar messages [ 945.653329] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff89a803b46000.ost_server_uuid 50 [ 946.193204] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff89a803b46000.ost_server_uuid in FULL state after 0 sec [ 948.055181] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff89a803b46000.ost_server_uuid 50 [ 948.584846] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff89a803b46000.ost_server_uuid in IDLE state after 0 sec [ 950.775990] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff89a803b46000.ost_server_uuid 50 [ 951.333400] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff89a803b46000.ost_server_uuid in FULL state after 0 sec [ 953.200601] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff89a803b46000.ost_server_uuid 50 [ 953.735157] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff89a803b46000.ost_server_uuid in IDLE state after 0 sec [ 957.903084] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff89a803b46000.ost_server_uuid 50 [ 958.430431] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff89a803b46000.ost_server_uuid in IDLE state after 0 sec [ 960.308953] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff89a803b46000.ost_server_uuid 50 [ 960.870768] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff89a803b46000.ost_server_uuid in IDLE state after 0 sec [ 961.465146] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 09:41:17 (1784122877) [ 962.421084] Lustre: DEBUG MARKER: Race attempt 0 [ 963.511627] Lustre: *** cfs_fail_loc=317, val=2147484440*** [ 963.513882] LustreError: 50562:0:(ldlm_lock.c:915:ldlm_lock_decref_internal()) cfs_race id 318 sleeping [ 963.517904] LustreError: 5552:0:(ldlm_lockd.c:2457:ldlm_callback_handler()) cfs_fail_race id 318 waking [ 963.521308] LustreError: 50562:0:(ldlm_lock.c:915:ldlm_lock_decref_internal()) cfs_fail_race id 318 awake: rc=4996 [ 963.526070] LustreError: 50562:0:(mdc_request.c:1507:mdc_read_page()) lustre-MDT0000-mdc-ffff89a803b46000: [0x200000401:0x90:0x0] lock enqueue fails: rc = -4 [ 964.057486] Lustre: DEBUG MARKER: Wait for 50412 50547 for 60 sec... [ 1026.387343] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 09:42:22 (1784122942) [ 1031.734849] Lustre: DEBUG MARKER: start test - cycle (0) [ 1053.460790] Lustre: DEBUG MARKER: start test - cycle (1) [ 1073.129587] Lustre: DEBUG MARKER: start test - cycle (2) [ 1094.290913] Lustre: DEBUG MARKER: start test - cycle (3) [ 1113.996920] Lustre: DEBUG MARKER: start test - cycle (4) [ 1135.197284] Lustre: DEBUG MARKER: start test - cycle (5) [ 1154.942359] Lustre: DEBUG MARKER: start test - cycle (6) [ 1175.904069] Lustre: DEBUG MARKER: start test - cycle (7) [ 1196.885329] Lustre: DEBUG MARKER: start test - cycle (8) [ 1216.874299] Lustre: DEBUG MARKER: start test - cycle (9) [ 1236.775241] Lustre: DEBUG MARKER: start test - cycle (10) [ 1260.611983] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 09:46:16 (1784123176) [ 1263.583116] Lustre: lustre-OST0001-osc-ffff89a81800a000: disconnect after 23s idle [ 1263.586184] Lustre: Skipped 2 previous similar messages [ 1285.190874] Lustre: DEBUG MARKER: == sanityn test 39a: file mtime does not change after rename ========================================================== 09:46:41 (1784123201) [ 1287.901581] Lustre: DEBUG MARKER: == sanityn test 39b: file mtime the same on clients with/out lock ========================================================== 09:46:44 (1784123204) [ 1291.272051] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 09:46:47 (1784123207) [ 1294.676802] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 09:46:50 (1784123210) [ 1294.741204] Lustre: *** cfs_fail_loc=411, val=0*** [ 1296.997449] Lustre: DEBUG MARKER: SKIP: sanityn test_40a skipping ALWAYS excluded test 40a [ 1297.621699] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 09:46:53 (1784123213) [ 1306.771253] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 09:47:02 (1784123222) [ 1315.775648] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 09:47:11 (1784123231) [ 1324.769838] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 09:47:20 (1784123240) [ 1332.752145] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 09:47:28 (1784123248) [ 1338.141897] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 09:47:34 (1784123254) [ 1344.003931] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 09:47:40 (1784123260) [ 1350.260739] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 09:47:46 (1784123266) [ 1355.947457] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 09:47:52 (1784123272) [ 1361.351104] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 09:47:57 (1784123277) [ 1366.742151] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 09:48:02 (1784123282) [ 1372.080234] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 09:48:08 (1784123288) [ 1377.817976] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 09:48:13 (1784123293) [ 1396.703157] Lustre: lustre-OST0001-osc-ffff89a803b46000: disconnect after 20s idle [ 1396.705314] Lustre: Skipped 3 previous similar messages [ 2000.864046] Lustre: lustre-OST0000-osc-ffff89a81800a000: disconnect after 24s idle [ 2104.858298] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 10:00:20 (1784124020) [ 2111.354626] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 10:00:27 (1784124027) [ 2117.838826] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 10:00:33 (1784124033) [ 2124.074785] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 10:00:40 (1784124040) [ 2129.702216] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 10:00:45 (1784124045) [ 2135.115877] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 10:00:51 (1784124051) [ 2140.214171] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 10:00:56 (1784124056) [ 2145.444754] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 10:01:01 (1784124061) [ 2150.682216] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 10:01:06 (1784124066) [ 2172.640311] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 10:01:28 (1784124088) [ 2177.892903] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 10:01:34 (1784124094) [ 2183.121412] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 10:01:39 (1784124099) [ 2188.632231] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 10:01:44 (1784124104) [ 2194.114337] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 10:01:50 (1784124110) [ 2199.798466] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 10:01:55 (1784124115) [ 2205.597119] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 10:02:01 (1784124121) [ 2211.248719] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 10:02:07 (1784124127) [ 2211.804526] Lustre: DEBUG MARKER: SKIP: sanityn test_43i needs >= 2 MDTs [ 2212.382935] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 10:02:08 (1784124128) [ 2257.465630] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 10:02:53 (1784124173) [ 2600.563641] hrtimer: interrupt took 15292982 ns [ 2801.627741] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 10:11:57 (1784124717) [ 2808.261840] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 10:12:04 (1784124724) [ 2814.068411] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 10:12:10 (1784124730) [ 2821.511670] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 10:12:17 (1784124737) [ 2830.303743] Lustre: lustre-OST0001-osc-ffff89a81800a000: disconnect after 20s idle [ 2830.310751] Lustre: Skipped 6 previous similar messages [ 2835.454751] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 10:12:31 (1784124751) [ 2848.703257] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 10:12:43 (1784124763) [ 2860.809812] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 10:12:56 (1784124776) [ 2872.015851] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 10:13:07 (1784124787) [ 2885.335896] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 10:13:20 (1784124800) [ 2887.205742] Lustre: DEBUG MARKER: SKIP: sanityn test_44i needs >= 2 MDTs [ 2889.569206] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 10:13:24 (1784124804) [ 2990.203476] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 10:15:05 (1784124905) [ 3000.541614] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 10:15:16 (1784124916) [ 3009.960414] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 10:15:25 (1784124925) [ 3019.194215] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 10:15:35 (1784124935) [ 3028.280179] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 10:15:44 (1784124944) [ 3037.796667] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 10:15:53 (1784124953) [ 3047.119507] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 10:16:02 (1784124962) [ 3054.888985] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 10:16:10 (1784124970) [ 3055.824794] Lustre: DEBUG MARKER: SKIP: sanityn test_45i needs >= 2 MDTs [ 3057.024168] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 10:16:12 (1784124972) [ 3444.706283] Lustre: lustre-OST0000-osc-ffff89a803b46000: disconnect after 24s idle [ 3444.710534] Lustre: Skipped 10 previous similar messages [ 3791.470485] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 10:28:27 (1784125707) [ 3799.696385] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 10:28:35 (1784125715) [ 3807.615691] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 10:28:43 (1784125723) [ 3815.058419] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 10:28:51 (1784125731) [ 3822.466483] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 10:28:58 (1784125738) [ 3829.435169] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 10:29:05 (1784125745) [ 3836.496269] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 10:29:12 (1784125752) [ 3843.556845] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 10:29:19 (1784125759) [ 3850.913406] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 10:29:26 (1784125766) [ 3851.740209] Lustre: DEBUG MARKER: SKIP: sanityn test_46i needs >= 2 MDTs [ 3852.652133] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 10:29:28 (1784125768) [ 3853.431529] Lustre: DEBUG MARKER: SKIP: sanityn test_47a needs >= 2 MDTs [ 3854.442435] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 10:29:30 (1784125770) [ 3855.240919] Lustre: DEBUG MARKER: SKIP: sanityn test_47b needs >= 2 MDTs [ 3856.175872] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 10:29:32 (1784125772) [ 3857.162451] Lustre: DEBUG MARKER: SKIP: sanityn test_47c needs >= 2 MDTs [ 3858.214963] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 10:29:34 (1784125774) [ 3858.960754] Lustre: DEBUG MARKER: SKIP: sanityn test_47d needs >= 2 MDTs [ 3859.799670] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 10:29:35 (1784125775) [ 3860.500368] Lustre: DEBUG MARKER: SKIP: sanityn test_47e needs >= 2 MDTs [ 3861.248545] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 10:29:37 (1784125777) [ 3862.004432] Lustre: DEBUG MARKER: SKIP: sanityn test_47f needs >= 2 MDTs [ 3862.760085] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 10:29:38 (1784125778) [ 3863.426528] Lustre: DEBUG MARKER: SKIP: sanityn test_47g needs >= 2 MDTs [ 3864.151150] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 10:29:40 (1784125780) [ 3864.301695] LustreError: 11889:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 sleeping for 2000ms [ 3866.391175] LustreError: 11889:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 awake [ 3872.455271] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 10:29:48 (1784125788) [ 3877.707623] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 10:29:53 (1784125793) [ 3877.877240] LustreError: 219465:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 3881.944141] LustreError: 219465:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 3881.968937] LustreError: 219465:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 3886.031110] LustreError: 219465:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 3886.070248] LustreError: 219482:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 3890.127132] LustreError: 219482:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 3893.420863] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 10:30:09 (1784125809) [ 3901.161360] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 10:30:17 (1784125817) [ 3905.296600] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 10:30:21 (1784125821) [ 3910.195897] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 10:30:26 (1784125826) [ 3935.723751] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 10:30:51 (1784125851) [ 3944.451506] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 10:31:00 (1784125860) [ 3952.680503] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 10:31:08 (1784125868) [ 3966.191664] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 10:31:22 (1784125882) [ 3976.879823] Lustre: DEBUG MARKER: == sanityn test 55e: rename race AB/BA under the same parent dir ========================================================== 10:31:32 (1784125892) [ 3977.547397] Lustre: DEBUG MARKER: SKIP: sanityn test_55e needs >= 2 MDTs [ 3978.302833] Lustre: DEBUG MARKER: == sanityn test 55f: rename: (P1/A -> P2/B) race with (P2/B -> P1/A) ========================================================== 10:31:34 (1784125894) [ 3991.734709] Lustre: DEBUG MARKER: == sanityn test 55g: rename: race with trylock =========== 10:31:47 (1784125907) [ 4006.700458] Lustre: DEBUG MARKER: == sanityn test 56a: test llverdev with single large stripe ========================================================== 10:32:02 (1784125922) [ 4043.421829] Lustre: DEBUG MARKER: == sanityn test 56b: test llverdev and partial verify of wide stripe file ========================================================== 10:32:39 (1784125959) [ 4090.222508] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 10:33:26 (1784126006) [ 4093.742906] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 4097.501907] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 10:33:33 (1784126013) [ 4101.253806] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 10:33:37 (1784126017) [ 4102.040302] Lustre: DEBUG MARKER: SKIP: sanityn test_71a ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 4102.761684] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 10:33:38 (1784126018) [ 4103.584299] Lustre: DEBUG MARKER: SKIP: sanityn test_71b ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 4104.266116] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 10:33:40 (1784126020) [ 4104.824155] Lustre: DEBUG MARKER: SKIP: sanityn test_71c support only ldiskfs ost [ 4105.437263] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 10:33:41 (1784126021) [ 4106.027294] Lustre: DEBUG MARKER: SKIP: sanityn test_71d ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 4106.634408] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 10:33:42 (1784126022) [ 4109.336245] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 10:33:45 (1784126025) [ 4111.806739] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 10:33:48 (1784126028) [ 4114.893533] LustreError: lustre-MDT0000-mdc-ffff89a803b46000: operation ldlm_enqueue to node 192.168.202.117@tcp failed: rc = -35 [ 4114.898347] LustreError: Skipped 1 previous similar message [ 4118.255133] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 10:33:54 (1784126034) [ 4118.397232] LustreError: 2358:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d sleeping for 2000ms [ 4120.479128] LustreError: 2358:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d awake [ 4126.330712] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 10:34:02 (1784126042) [ 4141.023155] Lustre: lustre-OST0000-osc-ffff89a81800a000: disconnect after 22s idle [ 4141.026747] Lustre: Skipped 3 previous similar messages [ 4156.267638] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 10:34:32 (1784126072) [ 4159.717609] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 10:34:35 (1784126075) [ 4164.580839] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 10:34:40 (1784126080) [ 4171.109686] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 10:34:47 (1784126087) [ 4177.825221] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 10:34:53 (1784126093) [ 4187.580759] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 10:35:03 (1784126103) [ 4196.153497] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 10:35:12 (1784126112) [ 4200.054501] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 10:35:16 (1784126116) [ 4204.510800] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 10:35:20 (1784126120) [ 4213.069812] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 10:35:29 (1784126129) [ 4269.362563] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 10:36:25 (1784126185) [ 4407.197568] Lustre: DEBUG MARKER: == sanityn test 77jb: check TBF-UID/GID NRS policy on files that don't belong to us ========================================================== 10:38:43 (1784126323) [ 4545.251425] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with UID/GID/JobID/OPCode expression ========================================================== 10:41:01 (1784126461) [ 4750.303238] Lustre: lustre-OST0001-osc-ffff89a803b46000: disconnect after 22s idle [ 4750.305626] Lustre: Skipped 17 previous similar messages [ 4904.102957] Lustre: DEBUG MARKER: == sanityn test 77kb: Check different granular TBF type combination: jobid+opcode ========================================================== 10:47:00 (1784126820) [ 4940.640946] Lustre: DEBUG MARKER: == sanityn test 77kc: Check different granular TBF type combination: nid+opcode ========================================================== 10:47:36 (1784126856) [ 4981.309375] Lustre: DEBUG MARKER: == sanityn test 77kd: Check different granular TBF type combination: nid+jobid ========================================================== 10:48:17 (1784126897) [ 5017.116675] Lustre: DEBUG MARKER: == sanityn test 77ke: Check different granular TBF type combination: jobid+opcode ========================================================== 10:48:53 (1784126933) [ 5094.666299] Lustre: DEBUG MARKER: == sanityn test 77kf: Check different granular TBF type combination: uid+gid ========================================================== 10:50:10 (1784127010) [ 5161.112834] Lustre: DEBUG MARKER: == sanityn test 77kg: check different granular TBF type combination: uid+opcode ========================================================== 10:51:17 (1784127077) [ 5283.829748] Lustre: DEBUG MARKER: == sanityn test 77kh: Verify that Project ID support for NRS TBF rule ========================================================== 10:53:20 (1784127200) [ 5284.938116] Lustre: Unmounted lustre-client [ 5286.009778] Lustre: Unmounted lustre-client [ 5329.796418] Lustre: Mounted lustre-client [ 5331.346544] Lustre: Mounted lustre-client [ 5332.419207] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5351.904203] Lustre: lustre-OST0000-osc-ffff89a818dc9000: disconnect after 20s idle [ 5351.907323] Lustre: Skipped 14 previous similar messages [ 5412.677404] Lustre: DEBUG MARKER: == sanityn test 77ki: Add rule with unsupported TBF type should fail for generic TBF ========================================================== 10:55:28 (1784127328) [ 5420.334532] Lustre: DEBUG MARKER: == sanityn test 77kj: Verify nodemap support for NRS TBF rule ========================================================== 10:55:36 (1784127336) [ 5538.667365] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 10:57:34 (1784127454) [ 5541.975344] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 10:57:38 (1784127458) [ 5592.726720] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 10:58:28 (1784127508) [ 5657.440635] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 10:59:33 (1784127573) [ 5661.168637] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 10:59:37 (1784127577) [ 5700.997872] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 11:00:17 (1784127617) [ 5713.004734] Lustre: DEBUG MARKER: == sanityn test 77r: Change type of tbf policy at run time ========================================================== 11:00:29 (1784127629) [ 5753.347206] Lustre: DEBUG MARKER: == sanityn test 77s: Check TBF LRU shrinker ============== 11:01:09 (1784127669) [ 5766.802258] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 11:01:23 (1784127683) [ 5769.821038] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 11:01:26 (1784127686) [ 5782.639458] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 11:01:38 (1784127698) [ 5783.181721] Lustre: DEBUG MARKER: SKIP: sanityn test_80a needs >= 2 MDTs [ 5783.763667] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 11:01:39 (1784127699) [ 5784.321863] Lustre: DEBUG MARKER: SKIP: sanityn test_80b needs >= 2 MDTs [ 5784.859326] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 11:01:41 (1784127701) [ 5785.402836] Lustre: DEBUG MARKER: SKIP: sanityn test_81a needs >= 2 MDTs [ 5786.020227] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 11:01:42 (1784127702) [ 5786.516401] Lustre: DEBUG MARKER: SKIP: sanityn test_81b We need at least 2 MDTs for this test [ 5787.112876] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 11:01:43 (1784127703) [ 5787.672231] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 5788.220617] Lustre: DEBUG MARKER: == sanityn test 81d: parallel rename file cross-dir on same MDT ========================================================== 11:01:44 (1784127704) [ 5814.142262] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 11:02:10 (1784127730) [ 5816.859378] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 11:02:13 (1784127733) [ 5817.382143] Lustre: DEBUG MARKER: SKIP: sanityn test_83 needs >= 2 MDTs [ 5817.944657] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 11:02:14 (1784127734) [ 5825.392852] Lustre: DEBUG MARKER: == sanityn test 85: Lustre API root cache race =========== 11:02:21 (1784127741) [ 5828.334701] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 11:02:24 (1784127744) [ 5828.870670] Lustre: DEBUG MARKER: SKIP: sanityn test_90 needs >= 2 MDTs [ 5829.500806] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 11:02:25 (1784127745) [ 5830.030302] Lustre: DEBUG MARKER: SKIP: sanityn test_91 needs >= 2 MDTs [ 5830.580475] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 11:02:26 (1784127746) [ 5831.063719] Lustre: DEBUG MARKER: SKIP: sanityn test_92 needs >= 2 MDTs [ 5831.608036] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 11:02:27 (1784127747) [ 5840.448938] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 11:02:36 (1784127756) [ 5840.534466] Lustre: DEBUG MARKER: write [ 5840.551400] LustreError: 263938:0:(ldlm_request.c:1533:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 sleeping for 5000ms [ 5842.555769] Lustre: DEBUG MARKER: kill 297329 [ 5842.557753] LustreError: 297329:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 sleeping for 6000ms [ 5845.647062] LustreError: 263938:0:(ldlm_request.c:1533:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 awake [ 5848.591161] LustreError: 297329:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 awake [ 5850.789713] Lustre: DEBUG MARKER: == sanityn test 95a: Check readpage() on a page that was removed from page cache ========================================================== 11:02:47 (1784127767) [ 5852.961337] LustreError: 297934:0:(rw.c:1865:ll_readpage()) cfs_fail_timeout id 1422 sleeping for 10000ms [ 5863.055179] LustreError: 297934:0:(rw.c:1865:ll_readpage()) cfs_fail_timeout id 1422 awake [ 5865.326102] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 11:03:01 (1784127781) [ 5865.423159] LustreError: 298514:0:(rw.c:2112:ll_readpage()) cfs_fail_timeout id 1424 sleeping for 5000ms [ 5867.503098] LustreError: 298514:0:(rw.c:2112:ll_readpage()) cfs_fail_timeout interrupted [ 5873.767815] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 11:03:09 (1784127789) [ 5874.324584] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [ 5874.886826] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 11:03:11 (1784127791) [ 5877.286715] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 11:03:13 (1784127793) [ 5879.687428] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 11:03:15 (1784127795) [ 5882.070515] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 11:03:18 (1784127798) [ 5884.327133] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 11:03:20 (1784127800) [ 5886.548630] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 11:03:22 (1784127802) [ 5888.844067] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 11:03:25 (1784127805) [ 5892.248498] Lustre: DEBUG MARKER: == sanityn test 102: Test open by handle of unlinked file ========================================================== 11:03:28 (1784127808) [ 5894.744021] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 11:03:30 (1784127810) [ 5895.405715] Lustre: *** cfs_fail_loc=415, val=0*** [ 5902.272417] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 11:03:38 (1784127818) [ 5902.838313] Lustre: DEBUG MARKER: SKIP: sanityn test_104 ldiskfs only test [ 5903.408555] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 11:03:39 (1784127819) [ 5903.489737] LustreError: 268457:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 sleeping for 5000ms [ 5903.493562] LustreError: 268457:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 3 previous similar messages [ 5908.583058] LustreError: 291957:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 5908.587079] LustreError: 291957:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 2 previous similar messages [ 5918.783078] LustreError: 268457:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 5918.785514] LustreError: 268457:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 4 previous similar messages [ 5921.319955] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 11:03:57 (1784127837) [ 5921.843614] Lustre: DEBUG MARKER: SKIP: sanityn test_106a Test only for ldiskfs and statx() supported [ 5922.439885] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 11:03:58 (1784127838) [ 5924.924068] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 11:04:01 (1784127841) [ 5927.236509] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 11:04:03 (1784127843) [ 5931.670428] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 11:04:07 (1784127847) [ 5940.017685] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 11:04:16 (1784127856) [ 5940.157445] LustreError: 250840:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 sleeping for 4000ms [ 5940.159572] LustreError: 250840:0:(osc_request.c:2989:osc_build_rpc()) Skipped 5 previous similar messages [ 5944.215136] LustreError: 250840:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 awake [ 5946.472509] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 11:04:22 (1784127862) [ 5947.187490] Lustre: Unmounted lustre-client [ 5948.056944] Lustre: DEBUG MARKER: Iteration 0 [ 5948.182735] LustreError: 309102:0:(llite_lib.c:1514:ll_fill_super()) cfs_race id 1417 sleeping [ 5948.182977] LustreError: 309103:0:(llite_lib.c:1514:ll_fill_super()) cfs_fail_race id 1417 waking [ 5948.187798] LustreError: 309102:0:(llite_lib.c:1514:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4998 [ 5948.232144] Lustre: Mounted lustre-client [ 5948.233279] Lustre: Skipped 1 previous similar message [ 5948.795159] Lustre: Unmounted lustre-client [ 5948.796286] Lustre: Skipped 1 previous similar message [ 5949.798655] Key type lgssc unregistered [ 5949.933821] LNet: 309440:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5949.939718] LNetError: 309440:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5949.955249] LNet: Removed LNI 192.168.202.17@tcp [ 5950.302105] Key type .llcrypt unregistered [ 5950.303094] Key type ._llcrypt unregistered [ 5950.638703] Key type ._llcrypt registered [ 5950.639803] Key type .llcrypt registered [ 5950.910929] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 5950.915786] alg: No test for adler32 (adler32-zlib) [ 5951.900743] Lustre: Lustre: Build Version: 2.17.54_162_g38d062c [ 5952.178572] LNet: Added LNI 192.168.202.17@tcp [8/256/0/180] [ 5953.799168] Key type lgssc registered [ 5954.339175] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5958.609617] Lustre: DEBUG MARKER: Iteration 1 [ 5958.756728] LustreError: 310261:0:(llite_lib.c:1514:ll_fill_super()) cfs_race id 1417 sleeping [ 5958.756763] LustreError: 310262:0:(llite_lib.c:1514:ll_fill_super()) cfs_fail_race id 1417 waking [ 5958.760833] LustreError: 310261:0:(llite_lib.c:1514:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4998 [ 5959.805781] Lustre: Mounted lustre-client [ 5959.806964] Lustre: Skipped 1 previous similar message [ 5960.289621] Lustre: Unmounted lustre-client [ 5961.378874] Key type lgssc unregistered [ 5961.488563] LNet: 310601:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5961.490924] LNetError: 310601:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5961.499787] LNet: Removed LNI 192.168.202.17@tcp [ 5961.736097] Key type .llcrypt unregistered [ 5961.737102] Key type ._llcrypt unregistered [ 5962.013828] Key type ._llcrypt registered [ 5962.016495] Key type .llcrypt registered [ 5962.205564] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 5962.210153] alg: No test for adler32 (adler32-zlib) [ 5963.065550] Lustre: Lustre: Build Version: 2.17.54_162_g38d062c [ 5963.159765] LNet: Added LNI 192.168.202.17@tcp [8/256/0/180] [ 5964.743241] Key type lgssc registered [ 5965.155154] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5968.645442] Lustre: DEBUG MARKER: Iteration 2 [ 5968.750373] LustreError: 311422:0:(llite_lib.c:1514:ll_fill_super()) cfs_race id 1417 sleeping [ 5968.751598] LustreError: 311423:0:(llite_lib.c:1514:ll_fill_super()) cfs_fail_race id 1417 waking [ 5968.754659] LustreError: 311422:0:(llite_lib.c:1514:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4998 [ 5969.794451] Lustre: Mounted lustre-client [ 5970.271074] Lustre: Unmounted lustre-client [ 5970.272101] Lustre: Skipped 1 previous similar message [ 5971.251946] Key type lgssc unregistered [ 5971.367512] LNet: 311760:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5971.369606] LNetError: 311760:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5971.379636] LNet: Removed LNI 192.168.202.17@tcp [ 5971.643112] Key type .llcrypt unregistered [ 5971.644205] Key type ._llcrypt unregistered [ 5971.900264] Key type ._llcrypt registered [ 5971.902018] Key type .llcrypt registered [ 5972.116886] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 5972.122301] alg: No test for adler32 (adler32-zlib) [ 5972.984251] Lustre: Lustre: Build Version: 2.17.54_162_g38d062c [ 5973.078746] LNet: Added LNI 192.168.202.17@tcp [8/256/0/180] [ 5974.663143] Key type lgssc registered [ 5975.058651] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5979.503263] Lustre: Mounted lustre-client [ 5981.827354] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 11:04:58 (1784127898) [ 6036.447143] Lustre: 313081:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784127898/real 1784127898] req@ffff89a83e33b800 x1870793685345024/t0(0) o36->lustre-MDT0000-mdc-ffff89a834eeb000@192.168.202.117@tcp:12/10 lens 496/440 e 0 to 1 dl 1784127953 ref 2 fl Rpc:XQr/200/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 6036.454899] Lustre: lustre-MDT0000-mdc-ffff89a834eeb000: Connection to lustre-MDT0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6036.463559] Lustre: lustre-MDT0000-mdc-ffff89a834eeb000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 6091.743202] Lustre: 313081:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784127953/real 1784127953] req@ffff89a83e33b800 x1870793685345024/t0(0) o36->lustre-MDT0000-mdc-ffff89a834eeb000@192.168.202.117@tcp:12/10 lens 496/440 e 0 to 1 dl 1784128008 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 6091.754225] Lustre: lustre-MDT0000-mdc-ffff89a834eeb000: Connection to lustre-MDT0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6091.765352] Lustre: lustre-MDT0000-mdc-ffff89a834eeb000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 6147.039172] Lustre: 313081:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784128008/real 1784128008] req@ffff89a83e33b800 x1870793685345024/t0(0) o36->lustre-MDT0000-mdc-ffff89a834eeb000@192.168.202.117@tcp:12/10 lens 496/440 e 0 to 1 dl 1784128063 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 6147.052209] Lustre: lustre-MDT0000-mdc-ffff89a834eeb000: Connection to lustre-MDT0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6147.062108] Lustre: lustre-MDT0000-mdc-ffff89a834eeb000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 6147.554354] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 11:07:43 (1784128063) [ 6148.045676] Lustre: DEBUG MARKER: SKIP: sanityn test_111 needs >= 2 MDTs [ 6148.606330] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 11:07:44 (1784128064) [ 6149.203618] Lustre: DEBUG MARKER: SKIP: sanityn test_112 We need at least 2 MDTs for this test [ 6149.787034] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 11:07:46 (1784128066) [ 6152.098381] Lustre: DEBUG MARKER: == sanityn test 114: implicit default LMV inherit ======== 11:07:48 (1784128068) [ 6152.696542] Lustre: DEBUG MARKER: SKIP: sanityn test_114 We need at least 2 MDTs for this test [ 6153.317559] Lustre: DEBUG MARKER: == sanityn test 115: ldiskfs doesn't check direntry for uniqueness ========================================================== 11:07:49 (1784128069) [ 6153.945289] Lustre: DEBUG MARKER: SKIP: sanityn test_115 ldiskfs only test [ 6154.594881] Lustre: DEBUG MARKER: == sanityn test 116: DNE: Set default LMV layout from a remote client ========================================================== 11:07:50 (1784128070) [ 6155.227889] Lustre: DEBUG MARKER: SKIP: sanityn test_116 needs >= 2 MDTs [ 6155.890714] Lustre: DEBUG MARKER: == sanityn test 121: trunc append race =================== 11:07:52 (1784128072) [ 6155.993854] LustreError: 315746:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 sleeping for 2000ms [ 6158.079102] LustreError: 315746:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 awake [ 6160.437660] Lustre: DEBUG MARKER: == sanityn test 200: service remains healthy while able to process request ========================================================== 11:07:56 (1784128076) [ 6178.783154] Lustre: 311952:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784128079/real 1784128079] req@ffff89a81a9a9880 x1870793685387008/t0(0) o4->lustre-OST0000-osc-ffff89a834eeb000@192.168.202.117@tcp:6/4 lens 4584/448 e 0 to 1 dl 1784128095 ref 2 fl Rpc:XQr/600/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 6178.783197] Lustre: lustre-OST0000-osc-ffff89a834eeb000: Connection to lustre-OST0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6178.791249] Lustre: 311952:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 6178.800226] Lustre: lustre-OST0000-osc-ffff89a834eeb000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 6195.167140] Lustre: 311955:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784128095/real 1784128095] req@ffff89a803629180 x1870793685386624/t0(0) o4->lustre-OST0000-osc-ffff89a834eeb000@192.168.202.117@tcp:6/4 lens 4584/448 e 0 to 1 dl 1784128111 ref 2 fl Rpc:XQr/602/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 6195.167200] Lustre: lustre-OST0000-osc-ffff89a834eeb000: Connection to lustre-OST0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6195.173355] Lustre: 311955:0:(client.c:2490:ptlrpc_expire_one_request()) Skipped 3 previous similar messages [ 6195.181437] Lustre: lustre-OST0000-osc-ffff89a834eeb000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 6210.335131] Lustre: 311955:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1784128111/real 1784128111] req@ffff89a803629180 x1870793685386624/t0(0) o4->lustre-OST0000-osc-ffff89a834eeb000@192.168.202.117@tcp:6/4 lens 4584/448 e 0 to 1 dl 1784128127 ref 2 fl Rpc:XQr/602/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 6210.343591] Lustre: lustre-OST0000-osc-ffff89a834eeb000: Connection to lustre-OST0000 (at 192.168.202.117@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 6210.352187] Lustre: lustre-OST0000-osc-ffff89a834eeb000: Connection restored to 192.168.202.117@tcp (at 192.168.202.117@tcp) [ 6226.849927] Lustre: DEBUG MARKER: oleg217-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff89a802dbe000.ost_server_uuid 50 [ 6227.366684] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff89a802dbe000.ost_server_uuid in IDLE state after 0 sec [ 6262.429753] Lustre: DEBUG MARKER: cleanup: ====================================================== [ 6263.190917] Lustre: DEBUG MARKER: == sanityn test complete, duration 6124 sec ============== 11:09:39 (1784128179) [ 6263.700939] Lustre: DEBUG MARKER: === sanityn: start cleanup 11:09:39 (1784128179) === [ 6458.498214] Lustre: Unmounted lustre-client [ 6461.447546] Lustre: DEBUG MARKER: === sanityn: finish cleanup 11:12:57 (1784128377) === [ 6462.830955] Lustre: Unmounted lustre-client [ 6505.551510] Key type lgssc unregistered [ 6506.022536] LNet: 318570:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6506.042751] LNetError: 318570:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6506.076493] LNet: Removed LNI 192.168.202.17@tcp [ 6507.704222] Key type .llcrypt unregistered [ 6507.705835] Key type ._llcrypt unregistered