[ 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 426063227 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2464 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2300 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022C0 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2374 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE2404 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE243C 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2300-0xbffe2373] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22ff] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2374-0xbffe2403] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe2404-0xbffe243b] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe243c-0xbffe2463] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059618 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829700K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.002304] x2apic enabled [ 0.003006] Switched APIC routing to physical x2apic. [ 0.004009] kvm-guest: setup PV IPIs [ 0.007000] ..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.007021] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008011] pid_max: default: 32768 minimum: 301 [ 0.009120] LSM: Security Framework initializing [ 0.010053] Yama: becoming mindful. [ 0.011028] SELinux: Initializing. [ 0.012016] *** VALIDATE selinux *** [ 0.019823] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024464] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.025168] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.026115] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027113] *** VALIDATE tmpfs *** [ 0.028441] *** VALIDATE proc *** [ 0.030071] *** VALIDATE cgroup *** [ 0.030965] *** VALIDATE cgroup2 *** [ 0.032129] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.033142] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.034006] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.035024] Spectre V2 : User space: Vulnerable [ 0.036006] Speculative Store Bypass: Vulnerable [ 0.039550] debug: unmapping init [mem 0xffffffffbe259000-0xffffffffbe260fff] [ 0.041158] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.042603] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.043022] ... version: 2 [ 0.043993] ... bit width: 48 [ 0.044011] ... generic registers: 4 [ 0.044974] ... value mask: 0000ffffffffffff [ 0.045013] ... max period: 00007fffffffffff [ 0.046011] ... fixed-purpose events: 3 [ 0.046915] ... event mask: 000000070000000f [ 0.047293] rcu: Hierarchical SRCU implementation. [ 0.049444] smp: Bringing up secondary CPUs ... [ 0.050513] x86: Booting SMP configuration: [ 0.051026] .... node #0, CPUs: #1 #2 #3 [ 0.055064] smp: Brought up 1 node, 4 CPUs [ 0.057031] smpboot: Max logical packages: 1 [ 0.058014] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.127123] node 0 deferred pages initialised in 67ms [ 0.131012] devtmpfs: initialized [ 0.132286] x86/mm: Memory block size: 128MB [ 0.135086] gcov: version magic: 0x41383552 [ 0.137427] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.138078] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.140475] pinctrl core: initialized pinctrl subsystem [ 0.142183] [ 0.142829] ************************************************************* [ 0.145013] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.147011] ** ** [ 0.150013] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.152015] ** ** [ 0.155012] ** This means that this kernel is built to expose internal ** [ 0.157013] ** IOMMU data structures, which may compromise security on ** [ 0.160022] ** your system. ** [ 0.162018] ** ** [ 0.164013] ** If you see this message and you are not debugging the ** [ 0.167012] ** kernel, report this immediately to your vendor! ** [ 0.169011] ** ** [ 0.171014] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.174013] ************************************************************* [ 0.177454] NET: Registered protocol family 16 [ 0.179468] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.181035] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.182044] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.185041] cpuidle: using governor menu [ 0.186673] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.188328] PCI: Using configuration type 1 for base access [ 0.189177] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.198232] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.200031] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.203104] cryptd: max_cpu_qlen set to 1000 [ 0.207284] ACPI: Added _OSI(Module Device) [ 0.209012] ACPI: Added _OSI(Processor Device) [ 0.211017] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.212013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.217293] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.223507] ACPI: Interpreter enabled [ 0.225056] ACPI: PM: (supports S0 S3 S4 S5) [ 0.226013] ACPI: Using IOAPIC for interrupt routing [ 0.228125] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.231540] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.242153] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.244038] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.246020] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.250073] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.254928] acpiphp: Slot [2] registered [ 0.256100] acpiphp: Slot [5] registered [ 0.257094] acpiphp: Slot [6] registered [ 0.258213] acpiphp: Slot [3] registered [ 0.259194] acpiphp: Slot [4] registered [ 0.260088] acpiphp: Slot [7] registered [ 0.262115] acpiphp: Slot [8] registered [ 0.263094] acpiphp: Slot [9] registered [ 0.265092] acpiphp: Slot [10] registered [ 0.266110] acpiphp: Slot [11] registered [ 0.268108] acpiphp: Slot [12] registered [ 0.269065] acpiphp: Slot [13] registered [ 0.270162] acpiphp: Slot [14] registered [ 0.271092] acpiphp: Slot [15] registered [ 0.272020] acpiphp: Slot [16] registered [ 0.272921] acpiphp: Slot [17] registered [ 0.274098] acpiphp: Slot [18] registered [ 0.276170] acpiphp: Slot [19] registered [ 0.277132] acpiphp: Slot [20] registered [ 0.279110] acpiphp: Slot [21] registered [ 0.280193] acpiphp: Slot [22] registered [ 0.282086] acpiphp: Slot [23] registered [ 0.283085] acpiphp: Slot [24] registered [ 0.284067] acpiphp: Slot [25] registered [ 0.285088] acpiphp: Slot [26] registered [ 0.286060] acpiphp: Slot [27] registered [ 0.286951] acpiphp: Slot [28] registered [ 0.287055] acpiphp: Slot [29] registered [ 0.288045] acpiphp: Slot [30] registered [ 0.289012] acpiphp: Slot [31] registered [ 0.289966] PCI host bridge to bus 0000:00 [ 0.291014] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.293018] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.294021] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.296016] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.298023] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.300020] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.301137] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.303938] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.306452] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.312015] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.317055] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.319063] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.320010] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.321010] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.323702] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.325785] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.328038] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.330634] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.335012] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.342016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.346014] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.350973] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.356017] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.361014] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.372067] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.382445] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.388014] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.394020] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.410069] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.417999] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.420252] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.421314] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.423344] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.425177] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.430120] iommu: Default domain type: Passthrough [ 0.432312] SCSI subsystem initialized [ 0.433084] ACPI: bus type USB registered [ 0.433963] usbcore: registered new interface driver usbfs [ 0.435056] usbcore: registered new interface driver hub [ 0.436142] usbcore: registered new device driver usb [ 0.438136] pps_core: LinuxPPS API ver. 1 registered [ 0.439007] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.441073] PTP clock support registered [ 0.443135] EDAC MC: Ver: 3.0.0 [ 0.444275] PCI: Using ACPI for IRQ routing [ 0.445541] NetLabel: Initializing [ 0.446007] NetLabel: domain hash size = 128 [ 0.446826] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.448113] NetLabel: unlabeled traffic allowed by default [ 0.449083] vgaarb: loaded [ 0.450184] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.452011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.457000] clocksource: Switched to clocksource kvm-clock [ 0.544156] VFS: Disk quotas dquot_6.6.0 [ 0.545271] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.546658] *** VALIDATE ramfs *** [ 0.547438] *** VALIDATE hugetlbfs *** [ 0.548479] pnp: PnP ACPI init [ 0.550357] pnp: PnP ACPI: found 6 devices [ 0.571654] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.573606] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.575061] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.576401] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.578015] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.579450] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.581296] NET: Registered protocol family 2 [ 0.583400] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.588183] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.591572] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.595397] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.597723] TCP: Hash tables configured (established 65536 bind 65536) [ 0.599793] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.602904] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.604620] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.606418] NET: Registered protocol family 1 [ 0.608473] RPC: Registered named UNIX socket transport module. [ 0.609783] RPC: Registered udp transport module. [ 0.611068] RPC: Registered tcp transport module. [ 0.611976] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.613286] NET: Registered protocol family 44 [ 0.614225] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.615607] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.617122] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.618395] PCI: CLS 0 bytes, default 64 [ 0.619528] Unpacking initramfs... [ 1.968672] debug: unmapping init [mem 0xffff9e893cc64000-0xffff9e893ffcffff] [ 1.972305] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 1.974293] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 1.977130] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.488947] Initialise system trusted keyrings [ 2.490272] Key type blacklist registered [ 2.491886] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.501801] zbud: loaded [ 2.505196] *** VALIDATE nfs *** [ 2.506497] *** VALIDATE nfs4 *** [ 2.507877] pstore: using deflate compression [ 2.511842] Platform Keyring initialized [ 2.619496] NET: Registered protocol family 38 [ 2.621356] Key type asymmetric registered [ 2.622796] Asymmetric key parser 'x509' registered [ 2.624654] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.627811] io scheduler mq-deadline registered [ 2.629393] io scheduler kyber registered [ 2.631096] io scheduler bfq registered [ 2.632857] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.635622] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.638554] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.640829] ACPI: Power Button [PWRF] [ 2.645645] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.651659] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.661557] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.690162] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.719227] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.724552] Non-volatile memory driver v1.3 [ 2.726465] Linux agpgart interface v0.103 [ 2.755561] virtio_blk virtio1: [vda] 134864 512-byte logical blocks (69.1 MB/65.9 MiB) [ 2.758020] vda: detected capacity change from 0 to 69050368 [ 2.784477] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 2.786973] vdb: detected capacity change from 0 to 1073741824 [ 2.792739] libphy: Fixed MDIO Bus: probed [ 2.798274] usbcore: registered new interface driver usbserial_generic [ 2.800593] usbserial: USB Serial support registered for generic [ 2.802946] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 2.808105] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 2.809870] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 2.812645] mousedev: PS/2 mouse device common for all mice [ 2.815409] rtc_cmos 00:05: RTC can wake from S4 [ 2.818431] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 2.820152] rtc_cmos 00:05: registered as rtc0 [ 2.823623] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 2.825534] intel_pstate: CPU model not supported [ 2.827695] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 2.827915] hid: raw HID events driver (C) Jiri Kosina [ 2.833329] usbcore: registered new interface driver usbhid [ 2.835523] usbhid: USB HID core driver [ 2.837790] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 2.837894] drop_monitor: Initializing network drop monitor service [ 2.843728] Initializing XFRM netlink socket [ 2.845772] NET: Registered protocol family 10 [ 2.849098] Segment Routing with IPv6 [ 2.850798] NET: Registered protocol family 17 [ 2.853031] mpls_gso: MPLS GSO support [ 2.860989] RAS: Correctable Errors collector initialized. [ 2.863329] AVX version of gcm_enc/dec engaged. [ 2.865182] AES CTR mode by8 optimization enabled [ 2.940726] sched_clock: Marking stable (2940705250, 0)->(3775870368, -835165118) [ 2.944597] registered taskstats version 1 [ 2.947783] Loading compiled-in X.509 certificates [ 2.950152] zswap: loaded using pool lzo/zbud [ 2.974815] Key type big_key registered [ 2.986739] Key type encrypted registered [ 2.988630] ima: No TPM chip found, activating TPM-bypass! [ 2.991062] ima: Allocated hash algorithm: sha1 [ 2.992875] ima: No architecture policies found [ 2.994712] evm: Initialising EVM extended attributes: [ 2.996070] evm: security.selinux [ 2.996890] evm: security.ima [ 2.997855] evm: security.capability [ 2.998832] evm: HMAC attrs: 0x1 [ 3.000966] rtc_cmos 00:05: setting system clock to 2026-06-01 13:59:07 UTC (1780322347) [ 3.007462] debug: unmapping init [mem 0xffffffffbf203000-0xffffffffbf3fffff] [ 3.010576] debug: unmapping init [mem 0xffffffffbdf82000-0xffffffffbe258fff] [ 3.023126] Write protecting the kernel read-only data: 28672k [ 3.026646] debug: unmapping init [mem 0xffffffffbc603000-0xffffffffbc7fffff] [ 3.029862] debug: unmapping init [mem 0xffffffffbcf14000-0xffffffffbcffffff] [ 3.062838] 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) [ 3.071724] systemd[1]: Detected virtualization kvm. [ 3.073703] systemd[1]: Detected architecture x86-64. [ 3.075781] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.102296] systemd[1]: No hostname configured. [ 3.104309] systemd[1]: Set hostname to . [ 3.106469] random: systemd: uninitialized urandom read (16 bytes read) [ 3.108905] systemd[1]: Initializing machine ID from random generator. [ 3.153546] random: ln: uninitialized urandom read (6 bytes read) [ 3.246162] random: systemd: uninitialized urandom read (16 bytes read) [ 3.248796] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 3.260345] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 3.267634] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control 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... Starting Apply Kernel Variables... [ OK ] Reached target Timers. Starting Setup Virtual Console... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... [ OK ] Reached target Sockets. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Reached target Swap. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 3.884640] device-mapper: uevent: version 1.0.3 [ 3.886457] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 4.582388] virtio_net virtio0 ens2: renamed from eth0 [ 4.620143] scsi host0: ata_piix [ 4.659519] scsi host1: ata_piix [ 4.661502] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 4.663706] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 8.406247] dracut-initqueue[584]: RTNETLINK answers: File exists [ 9.503694] random: crng init done [ 9.505341] random: 7 urandom warning(s) missed due to ratelimiting 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... [ 9.904440] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Sockets. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.132691] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.387800] SELinux: Disabled at runtime. [ 11.450305] 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) [ 11.458600] systemd[1]: Detected virtualization kvm. [ 11.460097] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 11.908592] systemd[1]: initrd-switch-root.service: Succeeded. [ 11.912101] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 11.916743] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 11.920541] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 11.923302] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 11.932755] systemd[1]: Starting Journal Service... Starting Journal Service... [ 11.942312] systemd[1]: Listening on RPCbind Server Activation Socket. [ OK ] Listening on RPCbind Server Activation Socket. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Apply Kernel Variables... [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target RPC Port Mapper. Starting Remount Root and Kernel File Systems... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Reached target rpc_pipefs.target. Activating swap /dev/disk/by-label/SWAP... [ OK ] Created slice User and Session Slice. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. Mounting Kernel Debug File System... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Slices. [ 12.134187] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on Process Core Dump Socket. Mounting Huge Pages File System... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Created slice system-getty.slice. Mounting POSIX Message Queue File System... [ OK ] Started Journal Service. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started 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 ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 12.516098] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 12.865962] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 12.891300] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.114563] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.142785] EDAC sbridge: Ver: 1.1.2 [ 14.253790] Key type dns_resolver registered [ 14.606405] NFS: Registering the id_resolver key type [ 14.609850] Key type id_resolver registered [ 14.611738] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Login Service... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. [ OK ] Started Login Service. Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ 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 Crash recovery kernel arming... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg252-client login: [ 47.181203] libcfs: loading out-of-tree module taints kernel. [ 47.332376] Key type ._llcrypt registered [ 47.335716] Key type .llcrypt registered [ 47.659311] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 47.669776] alg: No test for adler32 (adler32-zlib) [ 48.919369] Lustre: Lustre: Build Version: 2.17.53_34_g0f61aab [ 49.509929] LNet: Added LNI 192.168.202.52@tcp [8/256/0/180] [ 51.271192] Key type lgssc registered [ 54.710241] Lustre: Echo OBD driver; http://www.lustre.org/ [ 97.081848] hrtimer: interrupt took 4224263 ns [ 263.799905] Lustre: Mounted lustre-client [ 268.309080] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 281.878804] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing check_logdir /tmp/testlogs/ [ 287.605955] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing yml_node [ 289.247548] Lustre: lustre-OST0000-osc-ffff9e8988017800: disconnect after 23s idle [ 292.320503] Lustre: DEBUG MARKER: Client: 2.17.53.34 [ 294.908419] Lustre: DEBUG MARKER: MDS: 2.17.53.34 [ 297.215610] Lustre: DEBUG MARKER: OSS: 2.17.53.34 [ 299.102892] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Mon Jun 1 10:04:01 EDT 2026 [ 320.014222] Lustre: DEBUG MARKER: excepting tests: 27 40a [ 322.569673] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 324.609083] Lustre: DEBUG MARKER: === sanityn: start setup 10:04:27 (1780322667) === [ 325.579726] Lustre: Mounted lustre-client [ 330.101954] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing check_config_client /mnt/lustre [ 351.305828] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 363.740192] Lustre: DEBUG MARKER: === sanityn: finish setup 10:05:07 (1780322707) === [ 366.651738] Lustre: DEBUG MARKER: == sanityn test 0: do_node_vp() and do_facet_vp() do the right thing ========================================================== 10:05:09 (1780322709) [ 377.075154] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 10:05:19 (1780322719) [ 385.541959] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 10:05:28 (1780322728) [ 393.442606] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 10:05:36 (1780322736) [ 399.531939] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 10:05:43 (1780322743) [ 405.921222] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 10:05:49 (1780322749) [ 411.816299] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 10:05:55 (1780322755) [ 417.785381] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 10:06:01 (1780322761) [ 424.572941] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 10:06:07 (1780322767) [ 432.265796] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 10:06:14 (1780322774) [ 437.791154] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 10:06:21 (1780322781) [ 444.942651] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 10:06:28 (1780322788) [ 446.432907] Lustre: lustre-OST0001-osc-ffff9e8988017800: disconnect after 21s idle [ 446.444489] Lustre: Skipped 1 previous similar message [ 452.349363] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 10:06:35 (1780322795) [ 459.129936] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 10:06:42 (1780322802) [ 461.797275] Lustre: lustre-OST0000-osc-ffff9e89890d4000: disconnect after 23s idle [ 465.585527] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 10:06:48 (1780322808) [ 471.011268] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 10:06:54 (1780322814) [ 479.557382] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 10:07:02 (1780322822) [ 490.247736] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 10:07:12 (1780322832) [ 500.157186] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 10:07:22 (1780322842) [ 508.030652] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 10:07:30 (1780322850) [ 517.643358] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 10:07:40 (1780322860) [ 518.652656] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205289279518 file: /mnt/lustre/lockdir/lockfile=144115205289279517 [ 656.750342] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 10:10:00 (1780323000) [ 665.211584] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 10:10:08 (1780323008) [ 673.829253] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 10:10:16 (1780323016) [ 683.242413] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 10:10:25 (1780323025) [ 689.533505] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 10:10:32 (1780323032) [ 697.052682] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 10:10:40 (1780323040) [ 700.014923] Lustre: DEBUG MARKER: chmod [ 708.941558] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 10:10:51 (1780323051) [ 1369.117448] Lustre: DEBUG MARKER: == sanityn test 16a: 2500 iterations of dual-mount fsx === 10:21:53 (1780323713) [ 1424.351244] Lustre: lustre-OST0000-osc-ffff9e89890d4000: disconnect after 20s idle [ 1425.829401] Lustre: DEBUG MARKER: == sanityn test 16b: 2500 iterations of dual-mount fsx at small size ========================================================== 10:22:49 (1780323769) [ 1506.891375] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 10:24:10 (1780323850) [ 1613.886398] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 10:25:57 (1780323957) [ 1637.121358] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 10:26:20 (1780323980) [ 1641.636982] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 10:26:25 (1780323985) [ 1642.268767] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.324073] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.359148] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.397915] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.460900] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.500458] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.543771] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.588967] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.618747] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.673160] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.737709] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.777963] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.824560] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.866270] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.924347] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1642.971306] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.032833] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.078907] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.116563] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.157874] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.186949] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.230643] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.262578] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.301984] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.355636] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.407039] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.477507] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.567826] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.622625] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.669774] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.717437] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.756462] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.809733] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.888839] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1643.957546] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.036155] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.081336] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.134755] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.195809] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.251530] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.309019] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.373067] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.429870] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.477155] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.531994] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.584944] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.628887] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.670535] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.717900] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.788043] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.826699] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.904113] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1644.964957] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.020046] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.072252] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.113790] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.154462] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.204174] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.271910] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.321834] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.362622] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.426032] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.459849] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.498117] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.552527] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.600892] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.659790] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.713253] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.758484] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.809789] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.858696] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.900983] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1645.964944] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.019806] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.051691] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.097191] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.133183] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.186875] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.239700] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.294040] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.366264] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.403367] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.458460] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.501466] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.555527] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.609500] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.668468] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.743566] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.792618] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.872391] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.937727] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1646.982578] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.024894] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.065773] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.101485] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.173188] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.230595] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.274311] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.330393] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.376068] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.419948] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.475543] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.534124] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.574182] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.614535] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.659476] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.721869] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.788803] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.846694] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.884272] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1647.934407] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.007670] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.062768] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.103577] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.149851] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.183694] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.268471] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.331892] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.391481] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.443363] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.505775] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.556810] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.621502] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.683116] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.732546] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.777628] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.837618] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.883579] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.939583] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1648.978525] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.041773] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.087083] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.142866] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.188701] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.225902] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.285144] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.338522] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.379170] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.436359] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.482353] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.543491] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.628795] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.712930] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.778779] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.818094] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.864940] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.926492] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1649.971949] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.001947] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.036296] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.066266] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.104105] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.154843] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.246337] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.302050] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.348604] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.390641] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.452583] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.511160] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.563712] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.600409] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.633818] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.665757] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.726089] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.765795] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.825312] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.897541] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1650.947436] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.004747] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.087963] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.147828] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.205738] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.259517] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.306455] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.342762] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.397197] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.438622] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.489064] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.545807] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.602976] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.645809] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.698748] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.759276] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.813600] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.886994] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1651.976399] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.047660] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.133620] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.192474] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.242826] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.280371] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.324746] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.366253] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.428950] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.501487] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.536964] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.580824] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.633995] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.682383] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.732300] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.796803] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.871238] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1652.940400] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.005459] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.064088] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.106505] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.169890] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.229390] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.276549] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.317462] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.352576] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.391977] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.425801] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.474253] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.522113] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.570287] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.609995] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.655819] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.699482] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.750910] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.803539] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.864152] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.914901] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1653.966608] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.004611] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.056873] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.093378] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.141380] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.189231] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.223710] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.263538] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.314441] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.364334] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.395787] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.438492] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.483751] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.527255] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.572265] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.618295] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.687565] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.734148] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.785487] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.835327] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.919724] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1654.989834] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.048531] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.096945] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.140284] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.176973] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.217412] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.278403] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.309321] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.350939] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.393192] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.442150] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.484221] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.535233] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.584871] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.633782] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.674665] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.732053] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.773831] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.814272] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.871604] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.918418] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1655.992692] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.029432] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.083544] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.151105] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.207082] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.266136] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.321229] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.369994] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.411104] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.492200] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.533204] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.571574] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.613422] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.653694] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.712709] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.770296] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.824631] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.879269] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.930288] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1656.992525] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.058223] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.118074] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.156334] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.197416] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.253197] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.311242] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.378150] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.417641] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.494116] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.583535] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.635976] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.702672] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.774101] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.811670] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.876821] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.940611] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1657.992448] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.050276] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.103703] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.167626] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.223474] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.285426] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.341333] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.392365] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.466783] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.524582] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.592841] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.654328] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.709221] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.767784] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.815950] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.883201] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1658.952214] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.010624] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.073971] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.133696] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.178818] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.239815] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.299151] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.391819] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.433596] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.493109] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.546571] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.634140] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.696220] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.744942] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.794389] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.870903] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.874337] Lustre: lustre-OST0001-osc-ffff9e89890d4000: disconnect after 22s idle [ 1659.946073] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1659.999277] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.083924] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.140377] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.202336] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.258394] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.315807] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.371283] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.418577] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.483857] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.578149] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.639257] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.680251] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.720626] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.781610] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.824820] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.869131] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.930160] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1660.993237] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.055935] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.107230] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.163694] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.208024] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.282452] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.337349] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.385807] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.447682] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.514045] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.555636] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.617929] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.679544] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1661.727613] rw_seq_cst_vs_d (32524): drop_caches: 3 [ 1664.991147] Lustre: lustre-OST0001-osc-ffff9e8988017800: disconnect after 22s idle [ 1667.216143] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 10:26:50 (1780324010) [ 1667.600726] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1667.763329] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1667.848771] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1667.924895] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1667.991702] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1668.123476] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1668.251053] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1668.636953] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1668.816563] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1668.902406] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1668.953734] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.047603] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.177476] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.291750] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.343908] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.455791] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.489783] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.564553] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.604816] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.641299] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.713684] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1669.799616] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1670.229538] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1670.425276] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1670.522917] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1670.682944] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1670.750607] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1670.858261] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1670.904682] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1671.211588] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1671.345289] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1671.437548] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1671.540711] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1671.745608] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1671.820060] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1671.892547] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.044591] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.214401] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.356524] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.454426] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.496574] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.584813] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.694964] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.754867] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.797510] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1672.923206] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1673.370130] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1673.474145] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1673.612510] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1673.838228] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1673.886971] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1673.981244] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.023886] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.168373] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.237164] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.312675] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.359266] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.386954] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.476916] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.543124] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.594869] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.642291] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.677372] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.708733] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.797085] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.839099] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.882420] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1674.997634] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.032727] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.058614] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.217305] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.269371] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.305140] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.496936] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.528318] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.593818] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.712724] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.778243] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1675.903163] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.021664] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.068756] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.214574] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.285834] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.315541] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.344777] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.442666] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.569956] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.649908] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.739517] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1676.872437] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.020922] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.122894] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.193933] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.388326] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.429214] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.550739] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.724247] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1677.915135] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.008399] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.049794] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.087164] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.144460] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.175957] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.259458] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.378901] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.417626] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.572318] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.651973] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.681030] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.785163] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.828330] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.861536] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.895528] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.949532] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1678.993600] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.026434] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.075920] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.155232] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.228701] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.276147] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.321667] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.634169] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.782539] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.825375] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.860800] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1679.892074] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.041056] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.138813] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.217967] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.296133] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.389523] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.516493] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.610211] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.933927] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1680.969689] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.019522] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.162544] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.199064] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.246060] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.314358] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.346369] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.422886] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.580511] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1681.951073] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1682.217840] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1682.292064] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1682.444923] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1682.506357] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1682.790764] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1682.825478] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.031906] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.188794] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.290100] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.455217] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.516180] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.629992] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.716866] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.757488] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.804447] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1683.848188] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.035786] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.112595] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.274134] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.597794] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.663177] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.705995] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.747410] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1684.880195] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.021456] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.164107] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.262694] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.441189] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.508497] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.697464] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.738245] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.851872] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.898729] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1685.966440] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.004909] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.057598] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.158472] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.196269] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.252507] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.392470] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.445613] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.486391] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.532817] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.695180] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1686.921618] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1687.149904] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1687.238991] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1687.286990] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1687.319339] rw_seq_cst_vs_d (33114): drop_caches: 3 [ 1690.594229] Lustre: lustre-OST0000-osc-ffff9e8988017800: disconnect after 24s idle [ 1693.610673] Lustre: DEBUG MARKER: == sanityn test 16h: mmap read after truncate file ======= 10:27:16 (1780324036) [ 1698.693660] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 10:27:22 (1780324042) [ 1703.347315] Lustre: DEBUG MARKER: == sanityn test 16j: race dio with buffered i/o ========== 10:27:26 (1780324046) [ 1723.866323] Lustre: DEBUG MARKER: == sanityn test 16k: Parallel FSX and drop caches should not panic ========================================================== 10:27:47 (1780324067) [ 1724.080074] bash (35592): drop_caches: 3 [ 1727.296804] bash (35592): drop_caches: 3 [ 1730.432776] bash (35592): drop_caches: 3 [ 1733.568785] bash (35592): drop_caches: 3 [ 1736.670181] bash (35592): drop_caches: 3 [ 1739.784348] bash (35592): drop_caches: 3 [ 1743.388139] bash (35592): drop_caches: 3 [ 1746.732252] bash (35592): drop_caches: 3 [ 1749.880928] bash (35592): drop_caches: 3 [ 1753.001938] bash (35592): drop_caches: 3 [ 1757.148490] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 10:28:20 (1780324100) [ 1764.816605] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 10:28:28 (1780324108) [ 1877.789724] LustreError: lustre-OST0001-osc-ffff9e8988017800: operation ost_write to node 192.168.202.152@tcp failed: rc = -107 [ 1877.794369] Lustre: lustre-OST0001-osc-ffff9e8988017800: Connection to lustre-OST0001 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1877.808426] LustreError: lustre-OST0001-osc-ffff9e8988017800: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1877.827798] Lustre: 2405:0:(llite_lib.c:4192:ll_dirty_page_discard_warn()) lustre: dirty page discard: 192.168.202.152@tcp:/lustre/fid: [0x200000402:0x6f:0x0]// may get corrupted (rc -5) [ 1877.840511] LustreError: lustre-OST0000-osc-ffff9e89890d4000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1877.845612] Lustre: lustre-OST0001-osc-ffff9e8988017800: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 1877.852987] Lustre: 2406:0:(llite_lib.c:4192:ll_dirty_page_discard_warn()) lustre: dirty page discard: 192.168.202.152@tcp:/lustre/fid: [0x200000402:0x6e:0x0]// may get corrupted (rc -5) [ 1889.656889] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 10:30:33 (1780324233) [ 1897.312791] Lustre: DEBUG MARKER: loop 5 [ 1901.122482] Lustre: DEBUG MARKER: loop 10 [ 1905.331768] Lustre: DEBUG MARKER: loop 15 [ 1905.636719] Lustre: lustre-OST0001-osc-ffff9e8988017800: disconnect after 24s idle [ 1905.641899] Lustre: Skipped 1 previous similar message [ 1909.818798] Lustre: DEBUG MARKER: loop 20 [ 1916.392644] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 10:30:59 (1780324259) [ 1921.173943] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 10:31:04 (1780324264) [ 1926.569178] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 10:31:09 (1780324269) [ 1941.472517] Lustre: lustre-OST0001-osc-ffff9e8988017800: disconnect after 24s idle [ 1941.476730] Lustre: Skipped 1 previous similar message [ 1993.917355] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 10:32:17 (1780324337) [ 1999.228202] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 10:32:22 (1780324342) [ 2004.153178] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 10:32:27 (1780324347) [ 2009.761667] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 10:32:33 (1780324353) [ 2016.224950] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 10:32:39 (1780324359) [ 2022.292562] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 10:32:45 (1780324365) [ 2029.319021] Lustre: DEBUG MARKER: == sanityn test 26c: set-in-past on open file is not lost on close ========================================================== 10:32:52 (1780324372) [ 2035.249458] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 2036.704913] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 10:33:00 (1780324380) [ 2044.208144] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 10:33:07 (1780324387) [ 2044.519793] Lustre: *** cfs_fail_loc=314, val=0*** [ 2045.536118] Lustre: *** cfs_fail_loc=314, val=0*** [ 2045.543978] Lustre: Skipped 2 previous similar messages [ 2050.757519] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 10:33:13 (1780324393) [ 2054.111378] Lustre: lustre-OST0000-osc-ffff9e8988017800: disconnect after 23s idle [ 2054.117489] Lustre: Skipped 3 previous similar messages [ 2059.521595] Lustre: *** cfs_fail_loc=314, val=0*** [ 2059.622632] LustreError: lustre-OST0000-osc-ffff9e89890d4000: operation ldlm_enqueue to node 192.168.202.152@tcp failed: rc = -107 [ 2059.634825] LustreError: Skipped 1 previous similar message [ 2059.636260] Lustre: lustre-OST0000-osc-ffff9e89890d4000: Connection to lustre-OST0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2059.644031] Lustre: Skipped 1 previous similar message [ 2059.648238] LustreError: lustre-OST0000-osc-ffff9e89890d4000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 2059.663496] LustreError: 46531:0:(ldlm_resource.c:1180:ldlm_resource_complain()) lustre-OST0000-osc-ffff9e89890d4000: namespace resource [0x280000400:0x6:0x0].0x0 (ffff9e89a0ebfa00) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 2059.685395] Lustre: lustre-OST0000-osc-ffff9e89890d4000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 2059.697715] Lustre: Skipped 1 previous similar message [ 2065.306241] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 10:33:28 (1780324408) [ 2065.694335] LustreError: 47121:0:(file.c:822:ll_intent_file_open()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 2068.727185] LustreError: 47121:0:(file.c:822:ll_intent_file_open()) cfs_fail_timeout id 1419 awake [ 2074.166520] Lustre: DEBUG MARKER: == sanityn test 31s: open should not revalidate invalid dentry ========================================================== 10:33:37 (1780324417) [ 2080.828228] Lustre: DEBUG MARKER: == sanityn test 31t: getattr should not revalidate invalid dentry ========================================================== 10:33:44 (1780324424) [ 2087.358953] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 2088.634529] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 10:33:52 (1780324432) [ 2089.960148] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 2091.127169] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-on-Lock-Cancel ========================================================== 10:33:54 (1780324434) [ 2095.081667] Lustre: lustre-MDT0000-mdc-ffff9e8988017800: Connection to lustre-MDT0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2105.315840] Lustre: lustre-OST0000-osc-ffff9e89890d4000: disconnect after 23s idle [ 2105.323487] LustreError: MGC192.168.202.152@tcp: Connection to MGS (at 192.168.202.152@tcp) was lost; in progress operations using this service will fail [ 2105.344499] Lustre: Evicted from MGS (at 192.168.202.152@tcp) after server handle changed from 0x79ccf0f9bf8eaf95 to 0x79ccf0f9bf988da7 [ 2105.359267] Lustre: MGC192.168.202.152@tcp: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 2131.225477] Lustre: DEBUG MARKER: == sanityn test 33d: dependent transactions should trigger COS ========================================================== 10:34:34 (1780324474) [ 2170.645144] Lustre: DEBUG MARKER: == sanityn test 33e: independent transactions shouldn't trigger COS ========================================================== 10:35:14 (1780324514) [ 2183.437508] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 10:35:27 (1780324527) [ 2197.471231] Lustre: lustre-OST0000-osc-ffff9e89890d4000: disconnect after 21s idle [ 2197.485133] Lustre: Skipped 1 previous similar message [ 2237.390483] Lustre: lustre-OST0001-osc-ffff9e89890d4000: Connection to lustre-OST0001 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2237.394386] LustreError: lustre-OST0001-osc-ffff9e8988017800: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 2237.395784] Lustre: Skipped 2 previous similar messages [ 2237.400662] Lustre: lustre-OST0001-osc-ffff9e8988017800: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 2237.404606] LustreError: lustre-OST0001-osc-ffff9e89890d4000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 2237.408600] Lustre: Skipped 2 previous similar messages [ 2247.624338] Lustre: lustre-OST0000-osc-ffff9e8988017800: Connection to lustre-OST0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 2247.643653] LustreError: lustre-OST0000-osc-ffff9e8988017800: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 2247.653189] Lustre: lustre-OST0000-osc-ffff9e8988017800: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 2247.658522] Lustre: Skipped 1 previous similar message [ 2263.190443] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9e8988017800.ost_server_uuid 50 [ 2264.057602] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9e8988017800.ost_server_uuid in FULL state after 0 sec [ 2266.221913] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9e8988017800.ost_server_uuid 50 [ 2267.026424] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9e8988017800.ost_server_uuid in IDLE state after 0 sec [ 2270.153828] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9e8988017800.ost_server_uuid 50 [ 2271.157990] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9e8988017800.ost_server_uuid in IDLE state after 0 sec [ 2273.440817] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9e8988017800.ost_server_uuid 50 [ 2274.518992] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9e8988017800.ost_server_uuid in IDLE state after 0 sec [ 2279.589638] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9e8988017800.ost_server_uuid 50 [ 2280.423626] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9e8988017800.ost_server_uuid in IDLE state after 0 sec [ 2282.219788] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9e8988017800.ost_server_uuid 50 [ 2282.994317] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9e8988017800.ost_server_uuid in IDLE state after 0 sec [ 2283.785599] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 10:37:07 (1780324627) [ 2285.288571] Lustre: DEBUG MARKER: Race attempt 0 [ 2287.314775] Lustre: DEBUG MARKER: Wait for 58444 58539 for 60 sec... [ 2350.467879] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 10:38:14 (1780324694) [ 2356.160160] Lustre: DEBUG MARKER: start test - cycle (0) [ 2371.812208] Lustre: DEBUG MARKER: start test - cycle (1) [ 2389.649115] Lustre: DEBUG MARKER: start test - cycle (2) [ 2409.409117] Lustre: DEBUG MARKER: start test - cycle (3) [ 2425.410137] Lustre: DEBUG MARKER: start test - cycle (4) [ 2445.945653] Lustre: DEBUG MARKER: start test - cycle (5) [ 2466.241941] Lustre: DEBUG MARKER: start test - cycle (6) [ 2486.621921] Lustre: DEBUG MARKER: start test - cycle (7) [ 2507.319403] Lustre: DEBUG MARKER: start test - cycle (8) [ 2527.444663] Lustre: DEBUG MARKER: start test - cycle (9) [ 2543.137456] Lustre: DEBUG MARKER: start test - cycle (10) [ 2567.863232] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 10:41:51 (1780324911) [ 2571.231217] Lustre: lustre-OST0001-osc-ffff9e89890d4000: disconnect after 23s idle [ 2571.235137] Lustre: Skipped 3 previous similar messages [ 2608.021196] Lustre: DEBUG MARKER: == sanityn test 39a: file mtime does not change after rename ========================================================== 10:42:31 (1780324951) [ 2611.548519] Lustre: DEBUG MARKER: == sanityn test 39b: file mtime the same on clients with/out lock ========================================================== 10:42:35 (1780324955) [ 2615.672505] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 10:42:39 (1780324959) [ 2619.918655] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 10:42:43 (1780324963) [ 2620.094682] Lustre: *** cfs_fail_loc=411, val=0*** [ 2623.310221] Lustre: DEBUG MARKER: SKIP: sanityn test_40a skipping ALWAYS excluded test 40a [ 2623.973409] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 10:42:47 (1780324967) [ 2633.451912] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 10:42:57 (1780324977) [ 2643.288164] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 10:43:07 (1780324987) [ 2652.908908] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 10:43:16 (1780324996) [ 2661.847949] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 10:43:25 (1780325005) [ 2668.378625] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 10:43:32 (1780325012) [ 2674.949883] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 10:43:38 (1780325018) [ 2681.458781] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 10:43:45 (1780325025) [ 2687.866286] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 10:43:51 (1780325031) [ 2694.522859] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 10:43:58 (1780325038) [ 2702.122449] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 10:44:05 (1780325045) [ 2709.279434] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 10:44:12 (1780325052) [ 2715.841379] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 10:44:19 (1780325059) [ 3339.231329] Lustre: lustre-OST0000-osc-ffff9e89890d4000: disconnect after 24s idle [ 3339.234366] Lustre: Skipped 7 previous similar messages [ 3474.642569] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 10:56:58 (1780325818) [ 3481.094934] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 10:57:05 (1780325825) [ 3487.620321] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 10:57:11 (1780325831) [ 3494.268719] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 10:57:18 (1780325838) [ 3500.651634] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 10:57:24 (1780325844) [ 3507.411511] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 10:57:31 (1780325851) [ 3514.666151] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 10:57:38 (1780325858) [ 3521.621538] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 10:57:45 (1780325865) [ 3528.028110] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 10:57:51 (1780325871) [ 3577.281171] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 10:58:41 (1780325921) [ 3584.697910] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 10:58:48 (1780325928) [ 3591.944085] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 10:58:55 (1780325935) [ 3598.564544] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 10:59:02 (1780325942) [ 3605.404916] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 10:59:09 (1780325949) [ 3612.542758] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 10:59:16 (1780325956) [ 3619.159365] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 10:59:22 (1780325962) [ 3625.716127] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 10:59:29 (1780325969) [ 3632.579419] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 10:59:36 (1780325976) [ 3689.144972] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 11:00:33 (1780326033) [ 3871.711810] Lustre: lustre-OST0000-osc-ffff9e8988017800: disconnect after 22s idle [ 3871.716777] Lustre: Skipped 6 previous similar messages [ 4287.234179] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 11:10:31 (1780326631) [ 4293.296819] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 11:10:37 (1780326637) [ 4299.258375] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 11:10:43 (1780326643) [ 4305.162221] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 11:10:49 (1780326649) [ 4311.404521] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 11:10:55 (1780326655) [ 4317.648310] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 11:11:01 (1780326661) [ 4323.913617] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 11:11:07 (1780326667) [ 4329.938881] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 11:11:13 (1780326673) [ 4335.972227] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 11:11:19 (1780326679) [ 4341.832426] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 11:11:25 (1780326685) [ 4404.029264] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 11:12:27 (1780326747) [ 4410.091589] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 11:12:33 (1780326753) [ 4417.043750] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 11:12:40 (1780326760) [ 4428.843350] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 11:12:52 (1780326772) [ 4439.584262] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 11:13:02 (1780326782) [ 4451.317983] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 11:13:14 (1780326794) [ 4464.535798] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 11:13:27 (1780326807) [ 4480.126330] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 11:13:42 (1780326822) [ 4480.991514] Lustre: lustre-OST0001-osc-ffff9e8988017800: disconnect after 22s idle [ 4480.995617] Lustre: Skipped 6 previous similar messages [ 4496.958489] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 11:13:59 (1780326839) [ 5400.683357] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 11:29:04 (1780327744) [ 5408.397428] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 11:29:12 (1780327752) [ 5416.064313] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 11:29:19 (1780327759) [ 5423.864650] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 11:29:27 (1780327767) [ 5426.143232] Lustre: lustre-OST0001-osc-ffff9e89890d4000: disconnect after 24s idle [ 5426.146139] Lustre: Skipped 1 previous similar message [ 5430.994697] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 11:29:34 (1780327774) [ 5438.633194] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 11:29:42 (1780327782) [ 5446.088703] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 11:29:49 (1780327789) [ 5454.490902] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 11:29:58 (1780327798) [ 5463.246336] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 11:30:06 (1780327806) [ 5470.590834] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 11:30:14 (1780327814) [ 5477.978720] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 11:30:21 (1780327821) [ 5487.750448] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 11:30:30 (1780327830) [ 5503.376369] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 11:30:46 (1780327846) [ 5522.639784] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 11:31:05 (1780327865) [ 5540.095730] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 11:31:21 (1780327881) [ 5555.201425] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 11:31:38 (1780327898) [ 5577.212263] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 11:32:00 (1780327920) [ 5577.757747] LustreError: 22684:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 sleeping for 2000ms [ 5579.839441] LustreError: 22684:0:(ldlm_lockd.c:2079:ldlm_handle_cp_callback()) cfs_fail_timeout id 410 awake [ 5590.479568] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 11:32:13 (1780327933) [ 5599.705295] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 11:32:22 (1780327942) [ 5600.102084] LustreError: 240650:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 5604.175667] LustreError: 240650:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 5604.214987] LustreError: 240650:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 5608.287231] LustreError: 240650:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 5608.360638] LustreError: 240656:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 5612.455173] LustreError: 240656:0:(glimpse.c:206:__cl_glimpse_size()) cfs_fail_timeout id 1404 awake [ 5620.035900] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 11:32:43 (1780327963) [ 5632.338035] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 11:32:55 (1780327975) [ 5640.134417] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 11:33:02 (1780327982) [ 5649.601666] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 11:33:12 (1780327992) [ 5683.639299] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 11:33:46 (1780328026) [ 5695.831685] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 11:33:59 (1780328039) [ 5708.517451] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 11:34:11 (1780328051) [ 5727.559454] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 11:34:30 (1780328070) [ 5742.048281] Lustre: DEBUG MARKER: == sanityn test 55e: rename race AB/BA under the same parent dir ========================================================== 11:34:45 (1780328085) [ 5762.201800] Lustre: DEBUG MARKER: == sanityn test 55f: rename: (P1/A -> P2/B) race with (P2/B -> P1/A) ========================================================== 11:35:04 (1780328104) [ 5781.133898] Lustre: DEBUG MARKER: == sanityn test 55g: rename: race with trylock =========== 11:35:24 (1780328124) [ 5803.085254] Lustre: DEBUG MARKER: == sanityn test 56a: test llverdev with single large stripe ========================================================== 11:35:45 (1780328145) [ 5822.667317] Lustre: DEBUG MARKER: == sanityn test 56b: test llverdev and partial verify of wide stripe file ========================================================== 11:36:06 (1780328166) [ 5957.242468] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 11:38:20 (1780328300) [ 5969.568060] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 5978.830539] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 11:38:41 (1780328321) [ 5988.040717] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 11:38:50 (1780328330) [ 5995.896031] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 11:38:58 (1780328338) [ 6002.792527] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 11:39:05 (1780328345) [ 6040.118456] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 11:39:43 (1780328383) [ 6088.983275] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 11:40:32 (1780328432) [ 6097.407797] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 11:40:40 (1780328440) [ 6104.993889] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 11:40:48 (1780328448) [ 6108.444259] LustreError: lustre-MDT0000-mdc-ffff9e8988017800: operation ldlm_enqueue to node 192.168.202.152@tcp failed: rc = -35 [ 6116.867651] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 11:40:59 (1780328459) [ 6117.413825] LustreError: 2404:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d sleeping for 2000ms [ 6119.495301] LustreError: 2404:0:(osc_request.c:3138:osc_enqueue_interpret()) cfs_fail_timeout id 31d awake [ 6129.397923] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 11:41:12 (1780328472) [ 6137.824114] Lustre: lustre-OST0000-osc-ffff9e89890d4000: disconnect after 21s idle [ 6137.831972] Lustre: Skipped 5 previous similar messages [ 6326.456675] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 11:44:29 (1780328669) [ 6333.655609] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 11:44:37 (1780328677) [ 6344.666590] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 11:44:48 (1780328688) [ 6357.665996] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 11:45:01 (1780328701) [ 6371.351609] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 11:45:14 (1780328714) [ 6391.727206] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 11:45:34 (1780328734) [ 6418.816472] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 11:46:01 (1780328761) [ 6431.037734] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 11:46:13 (1780328773) [ 6443.380495] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 11:46:26 (1780328786) [ 6465.248758] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 11:46:48 (1780328808) [ 6516.650869] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 11:47:40 (1780328860) [ 6645.385543] Lustre: DEBUG MARKER: == sanityn test 77jb: check TBF-UID/GID NRS policy on files that don't belong to us ========================================================== 11:49:48 (1780328988) [ 6766.797243] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with UID/GID/JobID/OPCode expression ========================================================== 11:51:50 (1780329110) [ 6767.583328] Lustre: lustre-OST0000-osc-ffff9e8988017800: disconnect after 20s idle [ 6767.586601] Lustre: Skipped 12 previous similar messages [ 7072.840788] Lustre: DEBUG MARKER: == sanityn test 77kb: Check different granular TBF type combination: jobid+opcode ========================================================== 11:56:56 (1780329416) [ 7098.523413] Lustre: DEBUG MARKER: == sanityn test 77kc: Check different granular TBF type combination: nid+opcode ========================================================== 11:57:22 (1780329442) [ 7129.040619] Lustre: DEBUG MARKER: == sanityn test 77kd: Check different granular TBF type combination: nid+jobid ========================================================== 11:57:52 (1780329472) [ 7154.934648] Lustre: DEBUG MARKER: == sanityn test 77ke: Check different granular TBF type combination: jobid+opcode ========================================================== 11:58:18 (1780329498) [ 7216.579765] Lustre: DEBUG MARKER: == sanityn test 77kf: Check different granular TBF type combination: uid+gid ========================================================== 11:59:20 (1780329560) [ 7272.491121] Lustre: DEBUG MARKER: == sanityn test 77kg: check different granular TBF type combination: uid+opcode ========================================================== 12:00:16 (1780329616) [ 7376.865422] Lustre: lustre-OST0000-osc-ffff9e8988017800: disconnect after 20s idle [ 7376.890784] Lustre: Skipped 14 previous similar messages [ 7403.833546] Lustre: DEBUG MARKER: == sanityn test 77kh: Verify that Project ID support for NRS TBF rule ========================================================== 12:02:25 (1780329745) [ 7408.543233] LustreError: 286986:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9e8988017800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 7408.622249] Lustre: Unmounted lustre-client [ 7413.268314] LustreError: 286999:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9e89890d4000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 7413.277098] LustreError: 286999:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 7413.425337] Lustre: Unmounted lustre-client [ 7543.233201] Lustre: Mounted lustre-client [ 7545.969087] Lustre: Mounted lustre-client [ 7549.025634] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7639.721808] Lustre: DEBUG MARKER: == sanityn test 77ki: Add rule with unsupported TBF type should fail for generic TBF ========================================================== 12:06:22 (1780329982) [ 7658.285956] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 12:06:40 (1780330000) [ 7671.458340] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 12:06:54 (1780330014) [ 7732.737394] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 12:07:55 (1780330075) [ 7818.424213] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 12:09:20 (1780330160) [ 7832.557534] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 12:09:35 (1780330175) [ 7940.685474] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 12:11:24 (1780330284) [ 7969.991438] Lustre: DEBUG MARKER: == sanityn test 77r: Change type of tbf policy at run time ========================================================== 12:11:53 (1780330313) [ 8022.275381] Lustre: DEBUG MARKER: == sanityn test 77s: Check TBF LRU shrinker ============== 12:12:45 (1780330365) [ 8058.335276] Lustre: lustre-OST0000-osc-ffff9e89b0d4a800: disconnect after 22s idle [ 8058.344100] Lustre: Skipped 7 previous similar messages [ 8068.217711] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 12:13:31 (1780330411) [ 8074.415822] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 12:13:37 (1780330417) [ 8089.705436] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 12:13:53 (1780330433) [ 8096.952583] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 12:14:00 (1780330440) [ 8197.723641] LustreError: lustre-MDT0001-mdc-ffff9e89b0d4a800: operation ldlm_enqueue to node 192.168.202.152@tcp failed: rc = -107 [ 8197.727650] Lustre: lustre-MDT0001-mdc-ffff9e89b0d4a800: Connection to lustre-MDT0001 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 8197.736613] LustreError: lustre-MDT0001-mdc-ffff9e89b0d4a800: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 8197.743175] LustreError: 306510:0:(file.c:252:ll_close_inode_openhandle()) lustre-clilmv-ffff9e89b0d4a800: inode [0x240000bd0:0x1a:0x0] mdc close failed: rc = -108 [ 8197.746970] Lustre: lustre-MDT0001-mdc-ffff9e89b0d4a800: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 8213.989207] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 12:15:57 (1780330557) [ 8224.136846] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 12:16:06 (1780330566) [ 8473.714740] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 12:20:16 (1780330816) [ 8476.009070] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 8478.438159] Lustre: DEBUG MARKER: == sanityn test 81d: parallel rename file cross-dir on same MDT ========================================================== 12:20:20 (1780330820) [ 8724.657263] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 12:24:27 (1780331067) [ 8734.068356] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 12:24:36 (1780331076) [ 8863.165788] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 12:26:46 (1780331206) [ 8877.694895] Lustre: DEBUG MARKER: == sanityn test 85: Lustre API root cache race =========== 12:27:00 (1780331220) [ 8889.389532] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 12:27:11 (1780331231) [ 9078.564507] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 12:30:21 (1780331421) [ 9267.229994] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 12:33:30 (1780331610) [ 9274.800069] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 12:33:37 (1780331617) [ 9293.834306] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 12:33:56 (1780331636) [ 9294.221514] Lustre: DEBUG MARKER: write [ 9294.269993] LustreError: 289393:0:(ldlm_request.c:1525:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 sleeping for 5000ms [ 9296.326257] Lustre: DEBUG MARKER: kill 336843 [ 9296.337919] LustreError: 336843:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 sleeping for 6000ms [ 9299.287226] LustreError: 289393:0:(ldlm_request.c:1525:ldlm_cli_cancel_req()) cfs_fail_timeout id 312 awake [ 9302.399130] LustreError: 336843:0:(ldlm_request.c:1393:ldlm_cli_cancel_local()) cfs_fail_timeout id 329 awake [ 9310.107241] Lustre: DEBUG MARKER: == sanityn test 95a: Check readpage() on a page that was removed from page cache ========================================================== 12:34:12 (1780331652) [ 9312.996060] LustreError: 337458:0:(rw.c:1868:ll_readpage()) cfs_fail_timeout id 1422 sleeping for 10000ms [ 9323.031854] LustreError: 337458:0:(rw.c:1868:ll_readpage()) cfs_fail_timeout id 1422 awake [ 9331.859753] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 12:34:34 (1780331674) [ 9332.277852] LustreError: 338046:0:(rw.c:2116:ll_readpage()) cfs_fail_timeout id 1424 sleeping for 5000ms [ 9334.367246] LustreError: 338046:0:(rw.c:2116:ll_readpage()) cfs_fail_timeout interrupted [ 9346.490563] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 12:34:49 (1780331689) [ 9348.119191] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [ 9350.353934] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 12:34:53 (1780331693) [ 9358.581030] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 12:35:01 (1780331701) [ 9366.394748] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 12:35:09 (1780331709) [ 9375.278178] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 12:35:18 (1780331718) [ 9383.781709] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 12:35:26 (1780331726) [ 9391.472953] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 12:35:34 (1780331734) [ 9399.259417] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 12:35:42 (1780331742) [ 9408.504973] Lustre: DEBUG MARKER: == sanityn test 102: Test open by handle of unlinked file ========================================================== 12:35:51 (1780331751) [ 9419.233708] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 12:36:01 (1780331761) [ 9421.243737] Lustre: *** cfs_fail_loc=415, val=0*** [ 9434.946373] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 12:36:17 (1780331777) [ 9468.303963] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 12:36:50 (1780331810) [ 9468.770117] LustreError: 288714:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 sleeping for 5000ms [ 9468.776694] LustreError: 288714:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 3 previous similar messages [ 9473.775250] LustreError: 288715:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 9473.787741] LustreError: 288715:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 2 previous similar messages [ 9483.889518] LustreError: 288714:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) cfs_fail_timeout id 416 awake [ 9483.895421] LustreError: 288714:0:(osc_lock.c:435:__osc_dlm_blocking_ast()) Skipped 3 previous similar messages [ 9497.750672] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 12:37:20 (1780331840) [ 9507.288457] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 12:37:30 (1780331850) [ 9517.039829] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 12:37:39 (1780331859) [ 9525.191691] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 12:37:48 (1780331868) [ 9535.417706] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 12:37:58 (1780331878) [ 9550.714664] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 12:38:13 (1780331893) [ 9551.409915] LustreError: 348796:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 sleeping for 4000ms [ 9551.414304] LustreError: 348796:0:(osc_request.c:2989:osc_build_rpc()) Skipped 6 previous similar messages [ 9555.473106] LustreError: 348796:0:(osc_request.c:2989:osc_build_rpc()) cfs_fail_timeout id 414 awake [ 9555.479259] LustreError: 348796:0:(osc_request.c:2989:osc_build_rpc()) Skipped 3 previous similar messages [ 9563.398814] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 12:38:26 (1780331906) [ 9569.082351] LustreError: 349506:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9e89b0d4a800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 9569.095034] LustreError: 349506:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 9569.175201] Lustre: Unmounted lustre-client [ 9573.129907] LustreError: 349527:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9e898723b800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 9573.141180] LustreError: 349527:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 9573.287379] Lustre: Unmounted lustre-client [ 9575.332587] Lustre: DEBUG MARKER: Iteration 0 [ 9576.367444] LustreError: 349691:0:(llite_lib.c:1393:ll_fill_super()) cfs_race id 1417 sleeping [ 9576.375830] LustreError: 349692:0:(llite_lib.c:1393:ll_fill_super()) cfs_fail_race id 1417 waking [ 9576.392313] LustreError: 349691:0:(llite_lib.c:1393:ll_fill_super()) cfs_fail_race id 1417 awake: rc=4992 [ 9576.662280] Lustre: Mounted lustre-client [ 9578.295745] LustreError: 349785:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9e8988017000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 9578.308235] LustreError: 349785:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [ 9578.386963] Lustre: Unmounted lustre-client [ 9581.570250] Key type lgssc unregistered [ 9581.804091] LNet: 350036:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9581.809346] LNetError: 350036:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [ 9581.829960] LNet: Removed LNI 192.168.202.52@tcp [ 9582.844529] Key type .llcrypt unregistered [ 9582.851333] Key type ._llcrypt unregistered [ 9583.741259] Key type ._llcrypt registered [ 9583.789616] Key type .llcrypt registered [ 9584.418487] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9584.444915] alg: No test for adler32 (adler32-zlib) [ 9586.044900] Lustre: Lustre: Build Version: 2.17.53_34_g0f61aab [ 9586.864147] LNet: Added LNI 192.168.202.52@tcp [8/256/0/180] [ 9588.728929] Key type lgssc registered [ 9590.890650] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9606.827394] Lustre: Mounted lustre-client [ 9607.589164] Lustre: Mounted lustre-client [ 9616.949700] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 12:39:19 (1780331959) [ 9635.295966] Lustre: 351382:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780331963/real 1780331963] req@ffff9e89b9104380 x1866813334892800/t0(0) o36->lustre-MDT0000-mdc-ffff9e89882d9000@192.168.202.152@tcp:12/10 lens 496/440 e 0 to 1 dl 1780331979 ref 2 fl Rpc:XQr/200/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 9635.336861] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection to lustre-MDT0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9635.413834] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 9650.655243] Lustre: 351382:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780331979/real 1780331979] req@ffff9e89b9104380 x1866813334892800/t0(0) o36->lustre-MDT0000-mdc-ffff9e89882d9000@192.168.202.152@tcp:12/10 lens 496/440 e 0 to 1 dl 1780331995 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 9650.731940] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection to lustre-MDT0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9650.802797] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 9667.039211] Lustre: 351382:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780331995/real 1780331995] req@ffff9e89b9104380 x1866813334892800/t0(0) o36->lustre-MDT0000-mdc-ffff9e89882d9000@192.168.202.152@tcp:12/10 lens 496/440 e 0 to 1 dl 1780332011 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 9667.091453] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection to lustre-MDT0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9667.160466] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 9683.428097] Lustre: 351382:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332011/real 1780332011] req@ffff9e89b9104380 x1866813334892800/t0(0) o36->lustre-MDT0000-mdc-ffff9e89882d9000@192.168.202.152@tcp:12/10 lens 496/440 e 0 to 1 dl 1780332027 ref 2 fl Rpc:XQr/202/ffffffff rc 0/-1 job:'ln.0' uid:0 gid:0 projid:4294967295 [ 9683.479287] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection to lustre-MDT0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9683.541728] Lustre: lustre-MDT0000-mdc-ffff9e89882d9000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 9690.699381] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 12:40:33 (1780332033) [ 9702.794595] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 12:40:45 (1780332045) [ 9715.910398] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 12:40:58 (1780332058) [ 9724.879703] Lustre: DEBUG MARKER: == sanityn test 114: implicit default LMV inherit ======== 12:41:07 (1780332067) [ 9753.413138] Lustre: DEBUG MARKER: == sanityn test 115: ldiskfs doesn't check direntry for uniqueness ========================================================== 12:41:36 (1780332096) [ 9791.560334] Lustre: DEBUG MARKER: == sanityn test 116: DNE: Set default LMV layout from a remote client ========================================================== 12:42:14 (1780332134) [ 9799.553864] Lustre: DEBUG MARKER: == sanityn test 117a: TCU: Init and enable Trash Can on MDTs ========================================================== 12:42:22 (1780332142) [ 9812.382665] Lustre: DEBUG MARKER: == sanityn test 117b: Move regular file and empty dir into trash can dir ========================================================== 12:42:34 (1780332154) [ 9828.851921] Lustre: DEBUG MARKER: == sanityn test 117c: Move deleted tree with multiple levels into trash ========================================================== 12:42:52 (1780332172) [ 9844.601632] Lustre: DEBUG MARKER: == sanityn test 117d: Per-User Trash can Type testing ==== 12:43:07 (1780332187) [ 9863.735725] Lustre: DEBUG MARKER: == sanityn test 117e: Undeleted dir in trash should keep its original xattrs ========================================================== 12:43:26 (1780332206) [ 9881.042626] Lustre: DEBUG MARKER: == sanityn test 117f: Uncache the dentry under the trash dir ========================================================== 12:43:44 (1780332224) [ 9902.399594] Lustre: DEBUG MARKER: == sanityn test 117g: Access .Trash for a non-striped directory ========================================================== 12:44:04 (1780332244) [ 9918.875227] Lustre: DEBUG MARKER: == sanityn test 121: trunc append race =================== 12:44:21 (1780332261) [ 9919.418727] LustreError: 361933:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 sleeping for 2000ms [ 9921.503314] LustreError: 361933:0:(lcommon_cl.c:99:cl_setattr_ost()) cfs_fail_timeout id 1436 awake [ 9930.740186] Lustre: DEBUG MARKER: == sanityn test 200: service remains healthy while able to process request ========================================================== 12:44:33 (1780332273) [ 9954.783188] Lustre: 350231:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332283/real 1780332283] req@ffff9e89a0744a80 x1866813336063616/t0(0) o4->lustre-OST0000-osc-ffff9e89882d9000@192.168.202.152@tcp:6/4 lens 4584/448 e 0 to 1 dl 1780332299 ref 2 fl Rpc:XQr/600/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 9954.783552] Lustre: lustre-OST0000-osc-ffff9e89882d9000: Connection to lustre-OST0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9954.811212] Lustre: 350231:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 9954.892915] Lustre: lustre-OST0000-osc-ffff9e89882d9000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [ 9971.167299] Lustre: 350230:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332299/real 1780332299] req@ffff9e8985b33100 x1866813336063232/t0(0) o4->lustre-OST0000-osc-ffff9e89882d9000@192.168.202.152@tcp:6/4 lens 4584/448 e 0 to 1 dl 1780332315 ref 2 fl Rpc:XQr/602/ffffffff rc -11/-1 job:'dd.0' uid:0 gid:0 projid:0 [ 9971.167783] Lustre: lustre-OST0000-osc-ffff9e89882d9000: Connection to lustre-OST0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9971.194749] Lustre: 350230:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 6 previous similar messages [ 9971.267738] Lustre: lustre-OST0000-osc-ffff9e89882d9000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [10002.912030] Lustre: 350232:0:(client.c:2480:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1780332331/real 1780332331] req@ffff9e89a0745880 x1866813336061824/t0(0) o4->lustre-OST0000-osc-ffff9e89882d9000@192.168.202.152@tcp:6/4 lens 4584/448 e 0 to 1 dl 1780332347 ref 2 fl Rpc:XQr/602/ffffffff rc 0/-1 job:'dd.0' uid:0 gid:0 projid:0 [10002.914093] Lustre: lustre-OST0000-osc-ffff9e89882d9000: Connection to lustre-OST0000 (at 192.168.202.152@tcp) was lost; in progress operations using this service will wait for recovery to complete [10002.949919] Lustre: 350232:0:(client.c:2480:ptlrpc_expire_one_request()) Skipped 10 previous similar messages [10002.993195] Lustre: Skipped 1 previous similar message [10003.054191] Lustre: lustre-OST0000-osc-ffff9e89882d9000: Connection restored to 192.168.202.152@tcp (at 192.168.202.152@tcp) [10003.064960] Lustre: Skipped 1 previous similar message [10033.958704] Lustre: DEBUG MARKER: oleg252-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9e89882d9000.ost_server_uuid 50 [10035.600288] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9e89882d9000.ost_server_uuid in FULL state after 0 sec [10037.477551] Lustre: DEBUG MARKER: cleanup: ====================================================== [10039.542727] Lustre: DEBUG MARKER: == sanityn test complete, duration 9739 sec ============== 12:46:22 (1780332382) [10041.159375] Lustre: DEBUG MARKER: === sanityn: start cleanup 12:46:24 (1780332384) === [10332.345947] LustreError: 364021:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9e898a530000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [10332.419866] Lustre: Unmounted lustre-client [10335.885909] Lustre: DEBUG MARKER: === sanityn: finish cleanup 12:51:19 (1780332679) === [10338.256511] LustreError: 364329:0:(lov_obd.c:792:lov_cleanup()) lustre-clilov-ffff9e89882d9000: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [10338.268738] LustreError: 364329:0:(lov_obd.c:792:lov_cleanup()) Skipped 1 previous similar message [10338.342963] Lustre: Unmounted lustre-client [10403.255669] Key type lgssc unregistered [10403.603171] LNet: 365016:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10403.609098] LNetError: 365016:0:(acceptor.c:246:lnet_acceptor_remove_socket()) Interface ens2 not found [10403.634767] LNet: Removed LNI 192.168.202.52@tcp [10404.660187] Key type .llcrypt unregistered [10404.662415] Key type ._llcrypt unregistered