[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffd9fff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffda000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 452298285 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2421 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22BD 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 00227D (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2331 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23C1 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE23F9 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22bd-0xbffe2330] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22bc] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2331-0xbffe23c0] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23c1-0xbffe23f8] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe23f9-0xbffe2420] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059618 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829700K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001013] APIC: Switch to symmetric I/O mode setup [ 0.003301] x2apic enabled [ 0.004014] Switched APIC routing to physical x2apic. [ 0.005015] kvm-guest: setup PV IPIs [ 0.008000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008024] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009018] pid_max: default: 32768 minimum: 301 [ 0.010156] LSM: Security Framework initializing [ 0.011083] Yama: becoming mindful. [ 0.012051] SELinux: Initializing. [ 0.013088] *** VALIDATE selinux *** [ 0.022614] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.028099] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.029154] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030118] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.031146] *** VALIDATE tmpfs *** [ 0.032468] *** VALIDATE proc *** [ 0.034021] *** VALIDATE cgroup *** [ 0.035013] *** VALIDATE cgroup2 *** [ 0.036290] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.038178] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.039009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.040036] Spectre V2 : User space: Vulnerable [ 0.041010] Speculative Store Bypass: Vulnerable [ 0.044650] debug: unmapping init [mem 0xffffffff97e59000-0xffffffff97e60fff] [ 0.047176] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.048693] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.049027] ... version: 2 [ 0.050017] ... bit width: 48 [ 0.051014] ... generic registers: 4 [ 0.052015] ... value mask: 0000ffffffffffff [ 0.053016] ... max period: 00007fffffffffff [ 0.054019] ... fixed-purpose events: 3 [ 0.055015] ... event mask: 000000070000000f [ 0.056297] rcu: Hierarchical SRCU implementation. [ 0.058484] smp: Bringing up secondary CPUs ... [ 0.059609] x86: Booting SMP configuration: [ 0.060030] .... node #0, CPUs: #1 #2 #3 [ 0.063072] smp: Brought up 1 node, 4 CPUs [ 0.065017] smpboot: Max logical packages: 1 [ 0.066019] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.102673] node 0 deferred pages initialised in 35ms [ 0.107040] devtmpfs: initialized [ 0.108275] x86/mm: Memory block size: 128MB [ 0.111121] gcov: version magic: 0x41383552 [ 0.114327] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.117212] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.120461] pinctrl core: initialized pinctrl subsystem [ 0.123213] [ 0.123854] ************************************************************* [ 0.125017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.128013] ** ** [ 0.131014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.133023] ** ** [ 0.136012] ** This means that this kernel is built to expose internal ** [ 0.137020] ** IOMMU data structures, which may compromise security on ** [ 0.139019] ** your system. ** [ 0.141014] ** ** [ 0.144017] ** If you see this message and you are not debugging the ** [ 0.146021] ** kernel, report this immediately to your vendor! ** [ 0.148015] ** ** [ 0.150012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.152013] ************************************************************* [ 0.154566] NET: Registered protocol family 16 [ 0.156426] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.159085] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.162067] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.166011] cpuidle: using governor menu [ 0.167564] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.168565] PCI: Using configuration type 1 for base access [ 0.170147] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.178126] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.180040] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.183127] cryptd: max_cpu_qlen set to 1000 [ 0.186217] ACPI: Added _OSI(Module Device) [ 0.187013] ACPI: Added _OSI(Processor Device) [ 0.188015] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.190011] ACPI: Added _OSI(Processor Aggregator Device) [ 0.194161] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.199086] ACPI: Interpreter enabled [ 0.200059] ACPI: PM: (supports S0 S3 S4 S5) [ 0.201009] ACPI: Using IOAPIC for interrupt routing [ 0.202094] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.205380] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.215000] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.217047] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.219066] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.222078] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.226217] acpiphp: Slot [2] registered [ 0.227000] acpiphp: Slot [5] registered [ 0.227000] acpiphp: Slot [6] registered [ 0.228122] acpiphp: Slot [3] registered [ 0.229106] acpiphp: Slot [4] registered [ 0.231123] acpiphp: Slot [7] registered [ 0.232093] acpiphp: Slot [8] registered [ 0.233107] acpiphp: Slot [9] registered [ 0.235108] acpiphp: Slot [10] registered [ 0.236173] acpiphp: Slot [11] registered [ 0.237141] acpiphp: Slot [12] registered [ 0.239098] acpiphp: Slot [13] registered [ 0.240096] acpiphp: Slot [14] registered [ 0.242097] acpiphp: Slot [15] registered [ 0.243118] acpiphp: Slot [16] registered [ 0.245118] acpiphp: Slot [17] registered [ 0.246124] acpiphp: Slot [18] registered [ 0.248080] acpiphp: Slot [19] registered [ 0.249122] acpiphp: Slot [20] registered [ 0.250081] acpiphp: Slot [21] registered [ 0.252076] acpiphp: Slot [22] registered [ 0.253171] acpiphp: Slot [23] registered [ 0.254000] acpiphp: Slot [24] registered [ 0.254000] acpiphp: Slot [25] registered [ 0.254076] acpiphp: Slot [26] registered [ 0.255000] acpiphp: Slot [27] registered [ 0.257076] acpiphp: Slot [28] registered [ 0.258151] acpiphp: Slot [29] registered [ 0.260120] acpiphp: Slot [30] registered [ 0.262120] acpiphp: Slot [31] registered [ 0.263082] PCI host bridge to bus 0000:00 [ 0.265026] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.267033] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.270059] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.272031] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.276034] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.279024] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.280218] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.282916] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.286072] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.293012] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.296505] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.298018] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.300020] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.302018] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.305579] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.308879] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.311047] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.313698] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.317017] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.324760] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.328016] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.333141] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.336828] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.341016] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.353018] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.359260] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.364015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.368013] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.376015] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.384324] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.387398] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.389454] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.392388] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.395271] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.400161] iommu: Default domain type: Passthrough [ 0.402367] SCSI subsystem initialized [ 0.403128] ACPI: bus type USB registered [ 0.405132] usbcore: registered new interface driver usbfs [ 0.407202] usbcore: registered new interface driver hub [ 0.410165] usbcore: registered new device driver usb [ 0.412213] pps_core: LinuxPPS API ver. 1 registered [ 0.414010] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.416080] PTP clock support registered [ 0.418125] EDAC MC: Ver: 3.0.0 [ 0.421153] PCI: Using ACPI for IRQ routing [ 0.422814] NetLabel: Initializing [ 0.424013] NetLabel: domain hash size = 128 [ 0.426011] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.428082] NetLabel: unlabeled traffic allowed by default [ 0.431078] vgaarb: loaded [ 0.432260] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.434012] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.444000] clocksource: Switched to clocksource kvm-clock [ 0.553650] VFS: Disk quotas dquot_6.6.0 [ 0.555381] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.558830] *** VALIDATE ramfs *** [ 0.560400] *** VALIDATE hugetlbfs *** [ 0.562411] pnp: PnP ACPI init [ 0.565292] pnp: PnP ACPI: found 6 devices [ 0.584035] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.586056] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.587598] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.589488] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.590817] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.592302] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.594212] NET: Registered protocol family 2 [ 0.596650] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.601059] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.603356] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.607369] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.609668] TCP: Hash tables configured (established 65536 bind 65536) [ 0.611945] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.615578] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.618341] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.621332] NET: Registered protocol family 1 [ 0.623517] RPC: Registered named UNIX socket transport module. [ 0.625485] RPC: Registered udp transport module. [ 0.626985] RPC: Registered tcp transport module. [ 0.628549] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.630655] NET: Registered protocol family 44 [ 0.632105] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.634053] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.635974] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.638079] PCI: CLS 0 bytes, default 64 [ 0.639645] Unpacking initramfs... [ 2.110542] debug: unmapping init [mem 0xffff90397cc64000-0xffff90397ffcffff] [ 2.117097] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.119614] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.124275] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.568613] Initialise system trusted keyrings [ 2.570189] Key type blacklist registered [ 2.571909] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.579034] zbud: loaded [ 2.581261] *** VALIDATE nfs *** [ 2.582342] *** VALIDATE nfs4 *** [ 2.583681] pstore: using deflate compression [ 2.586545] Platform Keyring initialized [ 2.677725] NET: Registered protocol family 38 [ 2.680688] Key type asymmetric registered [ 2.682348] Asymmetric key parser 'x509' registered [ 2.684190] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.686801] io scheduler mq-deadline registered [ 2.688390] io scheduler kyber registered [ 2.690030] io scheduler bfq registered [ 2.691759] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.694559] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.697177] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.699832] ACPI: Power Button [PWRF] [ 2.705476] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.712548] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.720589] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.747509] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.773631] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.778195] Non-volatile memory driver v1.3 [ 2.779581] Linux agpgart interface v0.103 [ 2.809716] virtio_blk virtio1: [vda] 68040 512-byte logical blocks (34.8 MB/33.2 MiB) [ 2.812284] vda: detected capacity change from 0 to 34836480 [ 2.823702] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 2.826136] vdb: detected capacity change from 0 to 1073741824 [ 2.832972] libphy: Fixed MDIO Bus: probed [ 2.858231] usbcore: registered new interface driver usbserial_generic [ 2.860478] usbserial: USB Serial support registered for generic [ 2.862659] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 2.866414] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 2.868118] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 2.870495] mousedev: PS/2 mouse device common for all mice [ 2.873252] rtc_cmos 00:05: RTC can wake from S4 [ 2.875828] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 2.879207] rtc_cmos 00:05: registered as rtc0 [ 2.882284] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 2.882816] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 2.885468] intel_pstate: CPU model not supported [ 2.889614] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 2.894664] hid: raw HID events driver (C) Jiri Kosina [ 2.897190] usbcore: registered new interface driver usbhid [ 2.899314] usbhid: USB HID core driver [ 2.900989] drop_monitor: Initializing network drop monitor service [ 2.903419] Initializing XFRM netlink socket [ 2.905338] NET: Registered protocol family 10 [ 2.907964] Segment Routing with IPv6 [ 2.909421] NET: Registered protocol family 17 [ 2.911577] mpls_gso: MPLS GSO support [ 2.915895] RAS: Correctable Errors collector initialized. [ 2.918099] AVX version of gcm_enc/dec engaged. [ 2.919735] AES CTR mode by8 optimization enabled [ 2.996828] sched_clock: Marking stable (2996812258, 0)->(3932033369, -935221111) [ 2.999718] registered taskstats version 1 [ 3.001510] Loading compiled-in X.509 certificates [ 3.003379] zswap: loaded using pool lzo/zbud [ 3.022704] Key type big_key registered [ 3.032593] Key type encrypted registered [ 3.033924] ima: No TPM chip found, activating TPM-bypass! [ 3.035735] ima: Allocated hash algorithm: sha1 [ 3.037332] ima: No architecture policies found [ 3.039123] evm: Initialising EVM extended attributes: [ 3.041096] evm: security.selinux [ 3.042286] evm: security.ima [ 3.043245] evm: security.capability [ 3.044303] evm: HMAC attrs: 0x1 [ 3.046243] rtc_cmos 00:05: setting system clock to 2026-04-14 18:05:13 UTC (1776189913) [ 3.051190] debug: unmapping init [mem 0xffffffff98e03000-0xffffffff98ffffff] [ 3.053592] debug: unmapping init [mem 0xffffffff97b82000-0xffffffff97e58fff] [ 3.063090] Write protecting the kernel read-only data: 28672k [ 3.065552] debug: unmapping init [mem 0xffffffff96203000-0xffffffff963fffff] [ 3.067606] debug: unmapping init [mem 0xffffffff96b14000-0xffffffff96bfffff] [ 3.096952] 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.103647] systemd[1]: Detected virtualization kvm. [ 3.105220] systemd[1]: Detected architecture x86-64. [ 3.106675] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.135300] systemd[1]: No hostname configured. [ 3.136628] systemd[1]: Set hostname to . [ 3.138290] random: systemd: uninitialized urandom read (16 bytes read) [ 3.140331] systemd[1]: Initializing machine ID from random generator. [ 3.197130] random: ln: uninitialized urandom read (6 bytes read) [ 3.289203] random: systemd: uninitialized urandom read (16 bytes read) [ 3.292156] systemd[1]: Reached target Initrd Root Device. [ OK ] Reached target Initrd Root Device. [ 3.297731] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 3.302792] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on Journal Socket. [ OK ] Reached target Swap. [ OK ] Reached target Local Encrypted Volumes. Starting Setup Virtual Console... [ OK ] Reached target Slices. [ OK ] Started Memstrack Anylazing Service. [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Paths. [ OK ] Reached target Timers. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 3.905870] device-mapper: uevent: version 1.0.3 [ 3.908526] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 4.549935] virtio_net virtio0 ens2: renamed from eth0 [ 4.585365] scsi host0: ata_piix [ 4.589128] scsi host1: ata_piix [ 4.590675] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 4.593026] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 8.325212] dracut-initqueue[578]: RTNETLINK answers: File exists [ 9.548175] random: crng init done [ 9.549427] 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.904765] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Swap. [ OK ] Stopped target Local File Systems. Stopping udev Kernel Device Manager... [ OK ] Stopped target Sockets. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.095270] printk: systemd: 25 output lines suppressed due to ratelimiting [ 11.388558] SELinux: Disabled at runtime. [ 11.450085] 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.460760] systemd[1]: Detected virtualization kvm. [ 11.462506] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.063750] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.067607] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.072183] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.079545] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.085819] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.100364] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.109830] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target rpc_pipefs.target. Mounting Kernel Debug File System... Mounting Huge Pages File System... [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Started Forward Password Requests to Wall Directory Watch. Starting Apply Kernel Variables... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Created slice system-getty.slice. [ OK ] Listening on Process Core Dump 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 ] Reached target Local Encrypted Volumes. [ OK ] Reached target RPC Port Mapper. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. Activating swap /dev/disk/by-label/SWAP... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Reached target Paths. Mounting POSIX Message Queue File System... [ 12.277117] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. [ OK ] Started Apply Kernel Variables. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting 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 /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 12.605568] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ OK ] Started udev Coldplug all Devices. [ 12.946193] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.014564] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.097634] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.113748] EDAC sbridge: Ver: 1.1.2 [ 16.003614] Key type dns_resolver registered [ 16.828874] NFS: Registering the id_resolver key type [ 16.834958] Key type id_resolver registered [ 16.836860] Key type id_legacy registered [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started dnf makecache --timer. [ 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 D-Bus System Message Bus. Starting Login Service... [ OK ] Started irqbalance daemon. [ OK ] Started Daily Cleanup of Temporary Directories. Starting Restore /run/initramfs on shutdown... [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. Starting Network Manager... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ 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 Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg214-client login: [ 74.894665] libcfs: loading out-of-tree module taints kernel. [ 75.272086] alg: No test for adler32 (adler32-zlib) [ 76.122975] Key type ._llcrypt registered [ 76.127709] Key type .llcrypt registered [ 76.673233] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 77.365605] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 78.586228] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 78.593959] LNet: Accept secure, port 988 [ 80.407522] Key type lgssc registered [ 82.157827] Lustre: Echo OBD driver; http://www.lustre.org/ [ 206.352332] Lustre: Mounted lustre-client [ 211.889529] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 231.903620] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 23s idle [ 233.150992] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing check_logdir /tmp/testlogs/ [ 238.601809] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing yml_node [ 243.944739] Lustre: DEBUG MARKER: Client: 2.15.8.11 [ 247.239935] Lustre: DEBUG MARKER: MDS: 2.15.8.11 [ 250.843413] Lustre: DEBUG MARKER: OSS: 2.15.8.11 [ 253.057552] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Tue Apr 14 14:09:21 EDT 2026 [ 254.230124] hrtimer: interrupt took 2306547 ns [ 263.106776] Lustre: DEBUG MARKER: excepting tests: 27 28 102 [ 265.008817] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 266.066612] Lustre: Mounted lustre-client [ 274.386405] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing check_config_client /mnt/lustre [ 296.221458] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 309.477248] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 14:10:18 (1776190218) [ 316.427349] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 14:10:25 (1776190225) [ 323.989559] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 14:10:32 (1776190232) [ 331.464248] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 14:10:40 (1776190240) [ 337.844846] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 14:10:47 (1776190247) [ 345.170346] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 14:10:54 (1776190254) [ 353.303741] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 14:11:02 (1776190262) [ 355.373443] Lustre: DEBUG MARKER: SKIP: sanityn test_2f needs >= 2 MDTs [ 357.330507] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 14:11:06 (1776190266) [ 364.803179] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 14:11:13 (1776190273) [ 371.333865] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 14:11:20 (1776190280) [ 378.847448] Lustre: lustre-OST0001-osc-ffff9039c7e21800: disconnect after 21s idle [ 378.852951] Lustre: Skipped 1 previous similar message [ 379.742615] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 14:11:28 (1776190288) [ 387.675582] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 14:11:36 (1776190296) [ 394.207628] Lustre: lustre-OST0000-osc-ffff9039c92f2800: disconnect after 21s idle [ 395.646469] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 14:11:44 (1776190304) [ 402.533553] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 14:11:51 (1776190311) [ 409.383224] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 14:11:58 (1776190318) [ 409.568246] Lustre: lustre-OST0001-osc-ffff9039c7e21800: disconnect after 21s idle [ 417.042797] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 14:12:05 (1776190325) [ 425.116498] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 14:12:13 (1776190333) [ 433.515833] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 14:12:22 (1776190342) [ 440.418129] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 14:12:29 (1776190349) [ 448.214632] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 14:12:37 (1776190357) [ 449.012820] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205272502294 file: /mnt/lustre/lockdir/lockfile=144115205272502292 [ 590.565674] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 14:14:58 (1776190498) [ 599.982715] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 14:15:08 (1776190508) [ 608.620599] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 14:15:17 (1776190517) [ 616.055312] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 14:15:25 (1776190525) [ 624.012417] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 14:15:32 (1776190532) [ 632.396111] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 14:15:41 (1776190541) [ 634.253174] Lustre: DEBUG MARKER: chmod [ 642.520202] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 14:15:51 (1776190551) [ 651.629944] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7524352kB free gt MAXFREE 800000kB, increase 800000 (or reduce test fs size) to proceed [ 666.938642] Lustre: DEBUG MARKER: == sanityn test 16a: 500 iterations of dual-mount fsx ==== 14:16:15 (1776190575) [ 735.179699] Lustre: DEBUG MARKER: == sanityn test 16b: 500 iterations of dual-mount fsx at small size ========================================================== 14:17:23 (1776190643) [ 780.944699] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 14:18:09 (1776190689) [ 783.391543] Lustre: DEBUG MARKER: SKIP: sanityn test_16c dio on ldiskfs only [ 785.662685] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 14:18:14 (1776190694) [ 834.537987] Lustre: lustre-OST0000-osc-ffff9039c92f2800: disconnect after 21s idle [ 843.943495] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 14:19:12 (1776190752) [ 851.891404] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 14:19:20 (1776190760) [ 853.430932] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 853.520585] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 853.596650] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 853.685381] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 853.770960] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 853.818287] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 853.912440] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 853.987726] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.076400] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.156513] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.251654] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.353586] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.449461] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.581439] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.722358] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.795443] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.898581] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 854.992462] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.091052] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.178307] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.269704] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.360336] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.453686] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.553730] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.646200] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.748046] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.867154] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 855.959486] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.073526] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.180745] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.273961] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.371197] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.469563] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.550654] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.649504] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.784262] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 856.931956] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.072742] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.145240] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.230584] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.351205] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.451766] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.550472] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.648828] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.760519] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.867320] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 857.956626] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.023314] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.115473] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.208374] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.339394] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.430892] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.489236] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.573925] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.657235] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.736302] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.810636] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.901639] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 858.991405] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.090856] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.170329] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.258247] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.358518] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.442578] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.519183] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.601922] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.674639] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.755925] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.841236] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 859.941318] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.025521] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.107105] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.192453] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.278667] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.388351] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.460561] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.577509] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.687933] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.767566] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.852221] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 860.940352] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.037285] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.128170] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.262373] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.345492] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.427353] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.517169] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.623421] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.752168] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.851706] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 861.938897] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.066721] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.174667] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.301983] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.415936] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.531717] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.642392] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.749501] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 862.887684] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.006629] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.133758] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.213519] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.304254] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.376438] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.479987] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.584382] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.672849] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.760671] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.840301] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 863.925968] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.024786] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.144543] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.235540] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.315599] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.419465] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.508869] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.601951] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.696602] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.787257] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.861713] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 864.929448] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.017197] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.089577] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.163785] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.229894] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.250948] Lustre: lustre-OST0001-osc-ffff9039c92f2800: disconnect after 20s idle [ 865.297164] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.388957] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.477360] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.587494] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.687529] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.765309] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.875185] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 865.955581] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.062221] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.222419] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.321128] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.447078] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.552158] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.629900] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.736201] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.821376] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 866.915450] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.003333] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.155937] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.288356] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.404472] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.501497] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.600035] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.677909] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.744416] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.805770] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.900402] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 867.971155] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.059869] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.135203] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.180476] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.235473] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.314082] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.426104] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.514280] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.587979] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.656128] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.742352] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.825175] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 868.931120] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.000576] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.134393] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.233423] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.317259] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.364809] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.420198] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.483970] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.566821] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.667425] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 869.871145] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.009511] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.121464] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.233906] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.382910] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.482736] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.535219] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.591110] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.650974] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.749162] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.824152] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 870.896907] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.042811] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.156256] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.261159] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.395635] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.544916] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.646457] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.749540] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.854426] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 871.942556] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 872.038660] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 872.114193] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 872.257324] rw_seq_cst_vs_d (27555): drop_caches: 3 [ 881.459160] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 14:19:50 (1776190790) [ 882.405914] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 882.676739] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 882.723854] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 882.896647] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 882.988184] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.156060] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.234521] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.296790] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.432969] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.504169] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.612273] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.703936] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.842227] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 883.907152] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.064494] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.245150] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.371546] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.608156] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.667918] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.841020] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.883767] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.928417] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 884.971313] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.007281] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.112694] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.220512] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.372081] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.518281] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.659772] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.812034] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.882102] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 885.953143] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.091074] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.268597] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.335893] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.487426] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.625618] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.688761] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.774976] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 886.973090] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 887.195990] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 887.253955] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 887.402490] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 887.590561] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 887.762283] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 887.851746] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 888.204410] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 888.309061] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 888.491981] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 888.722958] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 888.952448] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 889.111705] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 889.173329] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 889.365625] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 889.419185] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 889.525867] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 889.679031] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 889.868743] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.037368] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.230977] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.349215] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.432236] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.539636] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.629597] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.775460] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 890.878637] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.074814] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.153564] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.233693] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.319973] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.407906] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.653565] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.835851] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 891.953312] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 892.097413] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 892.264559] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 892.419786] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 892.720183] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 892.902306] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 892.974859] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 893.189756] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 893.382476] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 893.483043] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 893.711905] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 893.782963] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 893.986959] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 894.149849] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 894.367803] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 894.440259] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 894.523631] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 894.593963] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 894.769694] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 894.926937] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.032323] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.181733] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.265758] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.349550] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.462185] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.553610] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.631703] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.833331] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 895.967932] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 21s idle [ 895.983374] Lustre: Skipped 1 previous similar message [ 895.987285] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 896.213617] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 896.326453] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 896.403960] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 896.593563] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 896.694851] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 896.813170] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 896.926127] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.045069] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.109626] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.265808] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.422603] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.620746] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.745630] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.812734] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 897.927070] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.054257] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.200536] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.282904] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.464879] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.609769] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.720540] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.878800] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 898.967074] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.125278] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.300455] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.401437] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.468926] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.527203] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.735466] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.864785] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 899.947611] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 900.005797] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 900.113193] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 900.291686] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 900.345001] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 900.510201] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 900.595964] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 900.732192] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 901.046831] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 901.169979] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 901.381694] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 901.564732] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 901.686838] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 901.842116] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 901.959613] rw_seq_cst_vs_d (28129): drop_caches: 3 [ 910.706054] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 14:20:19 (1776190819) [ 918.936464] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 14:20:27 (1776190827) [ 931.280976] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 14:20:39 (1776190839) [ 949.803629] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 14:20:58 (1776190858) [ 952.950726] Lustre: DEBUG MARKER: SKIP: sanityn test_19 not cache-capable obdfilter [ 954.883768] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 14:21:03 (1776190863) [ 962.538352] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 23s idle [ 962.559424] Lustre: Skipped 2 previous similar messages [ 963.281856] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 14:21:11 (1776190871) [ 972.178666] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 14:21:20 (1776190880) [ 1043.357863] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 14:22:32 (1776190952) [ 1052.034647] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 14:22:40 (1776190960) [ 1059.466278] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 14:22:48 (1776190968) [ 1067.988087] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 14:22:56 (1776190976) [ 1070.182717] Lustre: DEBUG MARKER: SKIP: sanityn test_25b needs >= 2 MDTs [ 1072.389447] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 14:23:01 (1776190981) [ 1075.167899] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 22s idle [ 1075.173165] Lustre: Skipped 4 previous similar messages [ 1081.718588] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 14:23:10 (1776190990) [ 1091.296460] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 1093.672174] Lustre: DEBUG MARKER: SKIP: sanityn test_28 skipping ALWAYS excluded test 28 [ 1096.276790] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 14:23:24 (1776191004) [ 1106.108044] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 14:23:34 (1776191014) [ 1106.441716] Lustre: *** cfs_fail_loc=314, val=0*** [ 1107.488620] Lustre: *** cfs_fail_loc=314, val=0*** [ 1107.500681] Lustre: Skipped 2 previous similar messages [ 1115.185415] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 14:23:44 (1776191024) [ 1131.239375] Lustre: *** cfs_fail_loc=314, val=0*** [ 1131.394361] LustreError: 11-0: lustre-OST0000-osc-ffff9039c92f2800: operation ldlm_enqueue to node 192.168.202.114@tcp failed: rc = -107 [ 1131.403626] Lustre: lustre-OST0000-osc-ffff9039c92f2800: Connection to lustre-OST0000 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1131.430075] LustreError: lustre-OST0000-osc-ffff9039c92f2800: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1131.450833] LustreError: 37378:0:(ldlm_resource.c:1127:ldlm_resource_complain()) lustre-OST0000-osc-ffff9039c92f2800: namespace resource [0x25:0x0:0x0].0x0 (000000006ad12f1d) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 1131.511168] Lustre: lustre-OST0000-osc-ffff9039c92f2800: Connection restored to (at 192.168.202.114@tcp) [ 1140.975670] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 14:24:09 (1776191049) [ 1141.407624] LustreError: 37959:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 1144.455149] LustreError: 37959:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1419 awake [ 1152.714330] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 1155.069084] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 14:24:23 (1776191063) [ 1157.340469] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 1159.763630] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-Lock-Cancel ========================================================== 14:24:28 (1776191068) [ 1161.324912] Lustre: DEBUG MARKER: SKIP: sanityn test_33c needs >= 2 MDTs [ 1164.461029] Lustre: DEBUG MARKER: == sanityn test 33d: DNE distributed operation should trigger COS ========================================================== 14:24:32 (1776191072) [ 1166.181465] Lustre: DEBUG MARKER: SKIP: sanityn test_33d needs >= 2 MDTs [ 1168.343674] Lustre: DEBUG MARKER: == sanityn test 33e: DNE local operation shouldn't trigger COS ========================================================== 14:24:37 (1776191077) [ 1170.252219] Lustre: DEBUG MARKER: SKIP: sanityn test_33e Need two or more clients, have 1 [ 1172.572797] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 14:24:41 (1776191081) [ 1217.482296] Lustre: lustre-OST0000-osc-ffff9039c7e21800: Connection to lustre-OST0000 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1217.529264] LustreError: lustre-OST0000-osc-ffff9039c92f2800: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1217.559878] LustreError: lustre-OST0000-osc-ffff9039c7e21800: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1217.562561] Lustre: lustre-OST0000-osc-ffff9039c92f2800: Connection restored to (at 192.168.202.114@tcp) [ 1217.599334] Lustre: Skipped 1 previous similar message [ 1227.722911] Lustre: lustre-OST0001-osc-ffff9039c7e21800: Connection to lustre-OST0001 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1227.738985] Lustre: Skipped 1 previous similar message [ 1227.771941] LustreError: lustre-OST0001-osc-ffff9039c7e21800: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1227.803184] Lustre: lustre-OST0001-osc-ffff9039c7e21800: Connection restored to (at 192.168.202.114@tcp) [ 1239.007278] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 22s idle [ 1239.010372] Lustre: Skipped 2 previous similar messages [ 1249.303548] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9039c7e21800.ost_server_uuid,osc.lustre-OST0000-osc-ffff9039c92f2800.ost_server_uuid 40 [ 1250.881811] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9039c7e21800.ost_server_uuid in IDLE state after 0 sec [ 1252.612397] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9039c92f2800.ost_server_uuid in IDLE state after 0 sec [ 1259.295058] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9039c7e21800.ost_server_uuid,osc.lustre-OST0001-osc-ffff9039c92f2800.ost_server_uuid 40 [ 1261.005205] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9039c7e21800.ost_server_uuid in IDLE state after 0 sec [ 1262.684760] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9039c92f2800.ost_server_uuid in FULL state after 0 sec [ 1270.754677] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9039c7e21800.ost_server_uuid,osc.lustre-OST0000-osc-ffff9039c92f2800.ost_server_uuid 40 [ 1272.732625] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9039c7e21800.ost_server_uuid in IDLE state after 0 sec [ 1274.214786] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9039c92f2800.ost_server_uuid in IDLE state after 0 sec [ 1281.403858] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9039c7e21800.ost_server_uuid,osc.lustre-OST0001-osc-ffff9039c92f2800.ost_server_uuid 40 [ 1282.894958] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9039c7e21800.ost_server_uuid in IDLE state after 0 sec [ 1284.652971] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9039c92f2800.ost_server_uuid in FULL state after 0 sec [ 1299.467402] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9039c7e21800.ost_server_uuid,osc.lustre-OST0000-osc-ffff9039c92f2800.ost_server_uuid 40 [ 1301.029850] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9039c7e21800.ost_server_uuid in IDLE state after 0 sec [ 1302.577637] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9039c92f2800.ost_server_uuid in IDLE state after 0 sec [ 1309.535298] Lustre: DEBUG MARKER: oleg214-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9039c7e21800.ost_server_uuid,osc.lustre-OST0001-osc-ffff9039c92f2800.ost_server_uuid 40 [ 1311.363676] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9039c7e21800.ost_server_uuid in IDLE state after 0 sec [ 1313.308724] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9039c92f2800.ost_server_uuid in FULL state after 0 sec [ 1315.476820] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 14:27:04 (1776191224) [ 1318.222405] Lustre: DEBUG MARKER: Race attempt 0 [ 1321.568561] Lustre: DEBUG MARKER: Wait for 44746 44761 for 60 sec... [ 1388.766887] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 14:28:17 (1776191297) [ 1398.327342] Lustre: DEBUG MARKER: start test - cycle (0) [ 1425.549673] Lustre: DEBUG MARKER: start test - cycle (1) [ 1452.656603] Lustre: DEBUG MARKER: start test - cycle (2) [ 1478.928812] Lustre: DEBUG MARKER: start test - cycle (3) [ 1498.324676] Lustre: DEBUG MARKER: start test - cycle (4) [ 1525.727294] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 21s idle [ 1525.729523] Lustre: Skipped 5 previous similar messages [ 1531.124901] Lustre: DEBUG MARKER: start test - cycle (5) [ 1566.695747] Lustre: DEBUG MARKER: start test - cycle (6) [ 1597.347767] Lustre: DEBUG MARKER: start test - cycle (7) [ 1624.237901] Lustre: DEBUG MARKER: start test - cycle (8) [ 1653.962056] Lustre: DEBUG MARKER: start test - cycle (9) [ 1690.654399] Lustre: DEBUG MARKER: start test - cycle (10) [ 1735.363554] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 14:34:04 (1776191644) [ 1813.813533] Lustre: DEBUG MARKER: == sanityn test 39a: test from 11063 ============================================================================================ 14:35:23 (1776191723) [ 1820.874246] Lustre: DEBUG MARKER: == sanityn test 39b: 11063 problem 1 ============================================================================================ 14:35:30 (1776191730) [ 1830.159990] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 14:35:39 (1776191739) [ 1838.575414] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 14:35:47 (1776191747) [ 1838.897969] Lustre: *** cfs_fail_loc=411, val=0*** [ 1845.259912] Lustre: DEBUG MARKER: == sanityn test 40a: pdirops: create vs others ======================================================================== 14:35:54 (1776191754) [ 1863.189798] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 14:36:12 (1776191772) [ 1881.337644] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 14:36:30 (1776191790) [ 1899.888725] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 14:36:49 (1776191809) [ 1916.230237] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 14:37:05 (1776191825) [ 1933.012391] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 14:37:22 (1776191842) [ 1945.449389] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 14:37:34 (1776191854) [ 1958.639269] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 14:37:47 (1776191867) [ 1974.746537] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 14:38:03 (1776191883) [ 1988.067385] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 14:38:17 (1776191897) [ 2003.639402] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 14:38:32 (1776191912) [ 2020.155222] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 14:38:49 (1776191929) [ 2034.470099] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 14:39:03 (1776191943) [ 2037.731215] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 21s idle [ 2037.737774] Lustre: Skipped 27 previous similar messages [ 2050.783829] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 14:39:19 (1776191959) [ 3183.340299] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 14:58:12 (1776193092) [ 3195.723466] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 14:58:24 (1776193104) [ 3208.941135] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 14:58:38 (1776193118) [ 3223.178689] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 14:58:52 (1776193132) [ 3236.804876] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 14:59:05 (1776193145) [ 3244.513412] Lustre: lustre-OST0001-osc-ffff9039c7e21800: disconnect after 23s idle [ 3244.517742] Lustre: Skipped 2 previous similar messages [ 3250.712070] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 14:59:19 (1776193159) [ 3264.586481] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 14:59:33 (1776193173) [ 3279.079771] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 14:59:48 (1776193188) [ 3291.455346] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 15:00:00 (1776193200) [ 3346.820191] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 15:00:55 (1776193255) [ 3363.077049] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 15:01:11 (1776193271) [ 3378.856934] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 15:01:28 (1776193288) [ 3393.576847] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 15:01:42 (1776193302) [ 3407.154295] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 15:01:56 (1776193316) [ 3423.111199] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 15:02:11 (1776193331) [ 3437.570062] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 15:02:26 (1776193346) [ 3453.233216] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 15:02:41 (1776193361) [ 3455.448129] Lustre: DEBUG MARKER: SKIP: sanityn test_43i needs >= 2 MDTs [ 3457.348682] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 15:02:46 (1776193366) [ 3610.175828] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 15:05:19 (1776193519) [ 4058.592143] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 24s idle [ 4058.604527] Lustre: Skipped 7 previous similar messages [ 4901.881450] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 15:26:51 (1776194811) [ 4915.489531] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 15:27:04 (1776194824) [ 4916.703877] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 22s idle [ 4916.709111] Lustre: Skipped 1 previous similar message [ 4929.064394] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 15:27:18 (1776194838) [ 4942.022627] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 15:27:31 (1776194851) [ 4956.102435] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 15:27:45 (1776194865) [ 4971.866217] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 15:28:00 (1776194880) [ 4985.939426] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 15:28:14 (1776194894) [ 4998.853114] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 15:28:27 (1776194907) [ 5014.928971] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 15:28:43 (1776194923) [ 5017.485873] Lustre: DEBUG MARKER: SKIP: sanityn test_44i needs >= 2 MDTs [ 5019.643788] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 15:28:48 (1776194928) [ 5122.372338] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 15:30:31 (1776195031) [ 5136.187156] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 15:30:45 (1776195045) [ 5149.982670] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 15:30:59 (1776195059) [ 5164.334913] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 15:31:13 (1776195073) [ 5178.410706] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 15:31:27 (1776195087) [ 5192.450663] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 15:31:41 (1776195101) [ 5206.665845] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 15:31:55 (1776195115) [ 5221.129071] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 15:32:10 (1776195130) [ 5222.687352] Lustre: DEBUG MARKER: SKIP: sanityn test_45i needs >= 2 MDTs [ 5224.376674] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 15:32:13 (1776195133) [ 5531.105199] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 22s idle [ 5531.116102] Lustre: Skipped 7 previous similar messages [ 6515.645252] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 15:53:44 (1776196424) [ 6528.985384] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 15:53:58 (1776196438) [ 6542.643108] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 15:54:11 (1776196451) [ 6544.863210] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 22s idle [ 6544.875640] Lustre: Skipped 4 previous similar messages [ 6555.155868] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 15:54:24 (1776196464) [ 6566.792602] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 15:54:36 (1776196476) [ 6579.794785] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 15:54:48 (1776196488) [ 6593.029431] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 15:55:02 (1776196502) [ 6610.950350] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 15:55:19 (1776196519) [ 6627.297522] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 15:55:35 (1776196535) [ 6629.198722] Lustre: DEBUG MARKER: SKIP: sanityn test_46i needs >= 2 MDTs [ 6632.030984] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 15:55:40 (1776196540) [ 6634.760433] Lustre: DEBUG MARKER: SKIP: sanityn test_47a needs >= 2 MDTs [ 6637.162244] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 15:55:45 (1776196545) [ 6639.086289] Lustre: DEBUG MARKER: SKIP: sanityn test_47b needs >= 2 MDTs [ 6641.353938] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 15:55:49 (1776196549) [ 6642.652290] Lustre: DEBUG MARKER: SKIP: sanityn test_47c needs >= 2 MDTs [ 6644.874644] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 15:55:53 (1776196553) [ 6646.771645] Lustre: DEBUG MARKER: SKIP: sanityn test_47d needs >= 2 MDTs [ 6648.472954] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 15:55:57 (1776196557) [ 6649.777762] Lustre: DEBUG MARKER: SKIP: sanityn test_47e needs >= 2 MDTs [ 6652.163519] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 15:56:00 (1776196560) [ 6653.893671] Lustre: DEBUG MARKER: SKIP: sanityn test_47f needs >= 2 MDTs [ 6655.558851] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 15:56:04 (1776196564) [ 6657.404814] Lustre: DEBUG MARKER: SKIP: sanityn test_47g needs >= 2 MDTs [ 6659.213328] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 15:56:08 (1776196568) [ 6659.670768] LustreError: 4992:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 410 sleeping for 2000ms [ 6661.760713] LustreError: 4992:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 410 awake [ 6671.503832] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 15:56:20 (1776196580) [ 6680.865951] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 15:56:29 (1776196589) [ 6681.210379] LustreError: 243422:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 6685.279240] LustreError: 243422:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 6685.302798] LustreError: 243422:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 6689.383563] LustreError: 243422:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 6689.455463] LustreError: 243428:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 6693.535314] LustreError: 243428:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 6700.952425] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 15:56:49 (1776196609) [ 6713.030441] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 15:57:02 (1776196622) [ 6724.980579] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 15:57:13 (1776196633) [ 6734.321781] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 15:57:23 (1776196643) [ 6766.004903] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 15:57:55 (1776196675) [ 6778.712224] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 15:58:07 (1776196687) [ 6792.944688] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 15:58:21 (1776196701) [ 6812.882522] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 15:58:41 (1776196721) [ 6828.480887] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 15:58:57 (1776196737) [ 6838.935713] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 6847.658417] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 15:59:16 (1776196756) [ 6856.650411] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 15:59:25 (1776196765) [ 6859.000915] Lustre: DEBUG MARKER: SKIP: sanityn test_71a ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 6860.658699] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 15:59:29 (1776196769) [ 6862.741913] Lustre: DEBUG MARKER: SKIP: sanityn test_71b ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 6864.868692] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 15:59:33 (1776196773) [ 6867.071766] Lustre: DEBUG MARKER: SKIP: sanityn test_71c support only ldiskfs ost [ 6869.072480] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 15:59:38 (1776196778) [ 6870.751685] Lustre: DEBUG MARKER: SKIP: sanityn test_71d ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 6872.369074] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 15:59:41 (1776196781) [ 6880.833730] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 15:59:49 (1776196789) [ 6889.238183] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 15:59:58 (1776196798) [ 6892.614764] LustreError: 11-0: lustre-MDT0000-mdc-ffff9039c7e21800: operation ldlm_enqueue to node 192.168.202.114@tcp failed: rc = -35 [ 6900.477339] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 16:00:09 (1776196809) [ 6901.277171] LustreError: 2218:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 31d sleeping for 2000ms [ 6903.378107] LustreError: 2218:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 31d awake [ 6913.710687] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 16:00:22 (1776196822) [ 6980.514670] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 16:01:29 (1776196889) [ 6990.550377] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 16:01:39 (1776196899) [ 7005.853101] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 16:01:54 (1776196914) [ 7025.136670] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 16:02:13 (1776196933) [ 7043.308924] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 16:02:32 (1776196952) [ 7069.636280] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 16:02:58 (1776196978) [ 7098.514967] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 16:03:27 (1776197007) [ 7109.937329] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 16:03:38 (1776197018) [ 7124.470329] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 16:03:52 (1776197032) [ 7148.818911] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 16:04:17 (1776197057) [ 7174.623223] Lustre: lustre-OST0001-osc-ffff9039c7e21800: disconnect after 23s idle [ 7174.630761] Lustre: Skipped 10 previous similar messages [ 7213.478392] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 16:05:22 (1776197122) [ 7368.498127] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with NID/JobID/OPCode expression ========================================================== 16:07:57 (1776197277) [ 7799.263808] Lustre: lustre-OST0000-osc-ffff9039c7e21800: disconnect after 23s idle [ 7799.268950] Lustre: Skipped 17 previous similar messages [ 7813.931962] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 16:15:23 (1776197723) [ 7823.521989] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 16:15:32 (1776197732) [ 7880.613455] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 16:16:29 (1776197789) [ 7972.111403] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 16:18:00 (1776197880) [ 7986.244518] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 16:18:15 (1776197895) [ 8110.415602] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 16:20:19 (1776198019) [ 8146.757565] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 16:20:55 (1776198055) [ 8156.002295] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 16:21:05 (1776198065) [ 8178.257396] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 16:21:26 (1776198086) [ 8180.287497] Lustre: DEBUG MARKER: SKIP: sanityn test_80a needs >= 2 MDTs [ 8182.825679] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 16:21:31 (1776198091) [ 8184.848673] Lustre: DEBUG MARKER: SKIP: sanityn test_80b needs >= 2 MDTs [ 8186.720355] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 16:21:35 (1776198095) [ 8187.909253] Lustre: DEBUG MARKER: SKIP: sanityn test_81a needs >= 2 MDTs [ 8189.702155] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 16:21:38 (1776198098) [ 8191.348601] Lustre: DEBUG MARKER: SKIP: sanityn test_81b We need at least 2 MDTs for this test [ 8193.274029] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 16:21:42 (1776198102) [ 8194.679309] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 8196.414210] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 16:21:45 (1776198105) [ 8203.111647] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 16:21:52 (1776198112) [ 8204.669688] Lustre: DEBUG MARKER: SKIP: sanityn test_83 needs >= 2 MDTs [ 8207.004242] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 16:21:55 (1776198115) [ 8219.849058] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 16:22:08 (1776198128) [ 8221.347529] Lustre: DEBUG MARKER: SKIP: sanityn test_90 needs >= 2 MDTs [ 8222.876373] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 16:22:12 (1776198132) [ 8224.499186] Lustre: DEBUG MARKER: SKIP: sanityn test_91 needs >= 2 MDTs [ 8226.199055] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 16:22:15 (1776198135) [ 8227.792385] Lustre: DEBUG MARKER: SKIP: sanityn test_92 needs >= 2 MDTs [ 8229.396878] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 16:22:18 (1776198138) [ 8244.924220] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 16:22:34 (1776198154) [ 8245.273774] Lustre: DEBUG MARKER: write [ 8245.315664] LustreError: 5002:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 sleeping for 5000ms [ 8247.381090] Lustre: DEBUG MARKER: kill 282915 [ 8247.390531] LustreError: 282915:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 329 sleeping for 6000ms [ 8250.320717] LustreError: 5002:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 awake [ 8253.425863] LustreError: 282915:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 329 awake [ 8260.157957] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 16:22:49 (1776198169) [ 8260.760133] LustreError: 283506:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1424 sleeping for 5000ms [ 8262.863149] LustreError: 283506:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 8273.138653] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 16:23:01 (1776198181) [ 8274.475875] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [ 8276.329912] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 16:23:05 (1776198185) [ 8284.056985] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 16:23:12 (1776198192) [ 8291.929820] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 16:23:20 (1776198200) [ 8299.265586] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 16:23:28 (1776198208) [ 8306.215467] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 16:23:35 (1776198215) [ 8313.031850] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 16:23:41 (1776198221) [ 8320.760421] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 16:23:49 (1776198229) [ 8328.749340] Lustre: DEBUG MARKER: SKIP: sanityn test_102 skipping ALWAYS excluded test 102 [ 8330.341623] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 16:23:59 (1776198239) [ 8331.895926] Lustre: *** cfs_fail_loc=415, val=0*** [ 8343.624545] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 16:24:12 (1776198252) [ 8345.298861] Lustre: DEBUG MARKER: SKIP: sanityn test_104 ldiskfs only test [ 8347.018874] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 16:24:16 (1776198256) [ 8347.297246] LustreError: 5003:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [ 8352.311318] LustreError: 5003:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 8357.423114] LustreError: 5003:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 8357.434215] LustreError: 5469:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [ 8357.443321] LustreError: 5469:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 8367.463209] LustreError: 5469:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 8367.469315] LustreError: 5469:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 8377.719715] LustreError: 5469:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [ 8377.738043] LustreError: 5469:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 8387.751743] LustreError: 5469:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 8387.760975] LustreError: 5469:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 8398.098352] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 16:25:07 (1776198307) [ 8399.518423] Lustre: DEBUG MARKER: SKIP: sanityn test_106a Test only for ldiskfs and statx() supported [ 8401.451301] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 16:25:10 (1776198310) [ 8409.513965] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 16:25:18 (1776198318) [ 8417.216479] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 16:25:26 (1776198326) [ 8426.166851] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 16:25:35 (1776198335) [ 8439.512752] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 16:25:48 (1776198348) [ 8440.051210] LustreError: 2218:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 414 sleeping for 4000ms [ 8440.056097] LustreError: 2218:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [ 8444.119437] LustreError: 2218:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 414 awake [ 8444.126289] LustreError: 2218:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 8451.156331] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 16:26:00 (1776198360) [ 8453.815070] Lustre: Unmounted lustre-client [ 8456.533566] Lustre: Unmounted lustre-client [ 8457.810521] Lustre: DEBUG MARKER: Iteration 1 [ 8458.271261] LustreError: 293546:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8458.272410] LustreError: 293545:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8458.296202] LustreError: 293546:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4993 [ 8458.464669] Lustre: Mounted lustre-client [ 8459.987101] Lustre: Unmounted lustre-client [ 8461.997836] Key type lgssc unregistered [ 8462.214119] LNet: 293901:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8463.264954] LNet: Removed LNI 192.168.202.14@tcp [ 8464.069310] Key type .llcrypt unregistered [ 8464.070882] Key type ._llcrypt unregistered [ 8465.189535] alg: No test for adler32 (adler32-zlib) [ 8465.953942] Key type ._llcrypt registered [ 8465.956163] Key type .llcrypt registered [ 8466.311519] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8467.029707] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8467.681861] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8467.686561] LNet: Accept secure, port 988 [ 8469.424047] Key type lgssc registered [ 8471.040880] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8483.881557] Lustre: DEBUG MARKER: Iteration 2 [ 8484.219977] LustreError: 294680:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8484.227700] LustreError: 294690:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8484.232995] LustreError: 294680:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [ 8485.539325] Lustre: Mounted lustre-client [ 8485.545715] Lustre: Skipped 1 previous similar message [ 8487.561640] Lustre: Unmounted lustre-client [ 8489.971913] Key type lgssc unregistered [ 8490.216844] LNet: 295040:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8491.297044] LNet: Removed LNI 192.168.202.14@tcp [ 8491.912910] Key type .llcrypt unregistered [ 8491.915604] Key type ._llcrypt unregistered [ 8492.614481] alg: No test for adler32 (adler32-zlib) [ 8493.376390] Key type ._llcrypt registered [ 8493.382109] Key type .llcrypt registered [ 8493.527745] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8493.874275] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8494.064432] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8494.068607] LNet: Accept secure, port 988 [ 8495.775236] Key type lgssc registered [ 8496.774481] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8507.199765] Lustre: DEBUG MARKER: Iteration 3 [ 8507.645287] LustreError: 295827:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8507.649253] LustreError: 295828:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8507.663783] LustreError: 295827:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [ 8508.990810] Lustre: Mounted lustre-client [ 8510.705979] Lustre: Unmounted lustre-client [ 8513.114703] Key type lgssc unregistered [ 8513.383262] LNet: 296186:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8514.465643] LNet: Removed LNI 192.168.202.14@tcp [ 8515.181638] Key type .llcrypt unregistered [ 8515.183842] Key type ._llcrypt unregistered [ 8516.177983] alg: No test for adler32 (adler32-zlib) [ 8516.983408] Key type ._llcrypt registered [ 8516.986804] Key type .llcrypt registered [ 8517.331166] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8517.691346] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8517.909650] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8517.915992] LNet: Accept secure, port 988 [ 8519.599985] Key type lgssc registered [ 8520.530453] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8531.022275] Lustre: DEBUG MARKER: Iteration 4 [ 8531.294842] LustreError: 296970:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8531.295044] LustreError: 296973:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8531.323991] LustreError: 296970:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [ 8532.526347] Lustre: Mounted lustre-client [ 8533.850727] Lustre: Unmounted lustre-client [ 8536.037510] Key type lgssc unregistered [ 8536.284751] LNet: 297324:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8537.317542] LNet: Removed LNI 192.168.202.14@tcp [ 8537.843565] Key type .llcrypt unregistered [ 8537.847048] Key type ._llcrypt unregistered [ 8538.753186] alg: No test for adler32 (adler32-zlib) [ 8539.575158] Key type ._llcrypt registered [ 8539.577412] Key type .llcrypt registered [ 8539.780940] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8540.013944] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8540.147395] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8540.150577] LNet: Accept secure, port 988 [ 8541.823163] Key type lgssc registered [ 8543.048787] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8553.470505] Lustre: DEBUG MARKER: Iteration 5 [ 8553.894655] LustreError: 298115:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8553.894944] LustreError: 298106:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8553.907078] LustreError: 298115:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [ 8555.174382] Lustre: Mounted lustre-client [ 8555.176807] Lustre: Skipped 1 previous similar message [ 8556.548588] Lustre: Unmounted lustre-client [ 8559.387272] Key type lgssc unregistered [ 8559.616926] LNet: 298466:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8560.677905] LNet: Removed LNI 192.168.202.14@tcp [ 8561.346722] Key type .llcrypt unregistered [ 8561.348461] Key type ._llcrypt unregistered [ 8562.262930] alg: No test for adler32 (adler32-zlib) [ 8563.022667] Key type ._llcrypt registered [ 8563.025376] Key type .llcrypt registered [ 8563.207774] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8563.499809] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8563.748954] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8563.757172] LNet: Accept secure, port 988 [ 8565.416720] Key type lgssc registered [ 8566.348469] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8576.994796] Lustre: DEBUG MARKER: Iteration 6 [ 8577.367841] LustreError: 299251:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8577.369318] LustreError: 299252:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8577.387112] LustreError: 299251:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [ 8578.623752] Lustre: Mounted lustre-client [ 8578.631626] Lustre: Skipped 1 previous similar message [ 8579.997727] Lustre: Unmounted lustre-client [ 8582.461500] Key type lgssc unregistered [ 8582.684757] LNet: 299609:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8583.726654] LNet: Removed LNI 192.168.202.14@tcp [ 8584.526146] Key type .llcrypt unregistered [ 8584.528790] Key type ._llcrypt unregistered [ 8585.579162] alg: No test for adler32 (adler32-zlib) [ 8586.350863] Key type ._llcrypt registered [ 8586.356369] Key type .llcrypt registered [ 8586.755431] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8587.148195] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8587.428341] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8587.432691] LNet: Accept secure, port 988 [ 8589.216214] Key type lgssc registered [ 8590.624483] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8605.837241] Lustre: DEBUG MARKER: Iteration 7 [ 8606.254299] LustreError: 300397:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8606.258322] LustreError: 300395:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8606.265896] LustreError: 300397:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4984 [ 8607.658656] Lustre: Mounted lustre-client [ 8609.595377] Lustre: Unmounted lustre-client [ 8612.119375] Key type lgssc unregistered [ 8612.320174] LNet: 300755:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8613.358563] LNet: Removed LNI 192.168.202.14@tcp [ 8614.039347] Key type .llcrypt unregistered [ 8614.044500] Key type ._llcrypt unregistered [ 8614.909400] alg: No test for adler32 (adler32-zlib) [ 8615.682452] Key type ._llcrypt registered [ 8615.687485] Key type .llcrypt registered [ 8615.925965] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8616.169539] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8616.343726] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8616.348826] LNet: Accept secure, port 988 [ 8618.007138] Key type lgssc registered [ 8619.184437] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8630.150575] Lustre: DEBUG MARKER: Iteration 8 [ 8630.512701] LustreError: 301542:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8630.523773] LustreError: 301543:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8630.536718] LustreError: 301542:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4980 [ 8631.795735] Lustre: Mounted lustre-client [ 8633.405791] Lustre: Unmounted lustre-client [ 8636.068193] Key type lgssc unregistered [ 8636.332314] LNet: 301896:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8637.416824] LNet: Removed LNI 192.168.202.14@tcp [ 8638.097573] Key type .llcrypt unregistered [ 8638.099621] Key type ._llcrypt unregistered [ 8639.099532] alg: No test for adler32 (adler32-zlib) [ 8639.874491] Key type ._llcrypt registered [ 8639.877242] Key type .llcrypt registered [ 8640.138049] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8640.575310] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8640.752425] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8640.754643] LNet: Accept secure, port 988 [ 8642.431122] Key type lgssc registered [ 8643.459479] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8655.305123] Lustre: DEBUG MARKER: Iteration 9 [ 8655.760047] LustreError: 302681:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8655.765735] LustreError: 302680:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8655.781247] LustreError: 302681:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [ 8657.203839] Lustre: Mounted lustre-client [ 8657.211017] Lustre: Skipped 1 previous similar message [ 8659.497940] Lustre: Unmounted lustre-client [ 8661.879847] Key type lgssc unregistered [ 8662.180310] LNet: 303040:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8663.205934] LNet: Removed LNI 192.168.202.14@tcp [ 8664.261413] Key type .llcrypt unregistered [ 8664.264246] Key type ._llcrypt unregistered [ 8665.185540] alg: No test for adler32 (adler32-zlib) [ 8665.944338] Key type ._llcrypt registered [ 8665.949813] Key type .llcrypt registered [ 8666.276851] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8666.736816] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8666.934966] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8666.942321] LNet: Accept secure, port 988 [ 8668.663117] Key type lgssc registered [ 8669.740840] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8680.704685] Lustre: DEBUG MARKER: Iteration 10 [ 8681.018609] LustreError: 303829:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8681.022457] LustreError: 303828:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8681.040764] LustreError: 303829:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [ 8682.292840] Lustre: Mounted lustre-client [ 8683.878043] Lustre: Unmounted lustre-client [ 8686.312844] Key type lgssc unregistered [ 8686.528839] LNet: 304187:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8687.590533] LNet: Removed LNI 192.168.202.14@tcp [ 8688.211700] Key type .llcrypt unregistered [ 8688.214992] Key type ._llcrypt unregistered [ 8689.069717] alg: No test for adler32 (adler32-zlib) [ 8689.827545] Key type ._llcrypt registered [ 8689.829570] Key type .llcrypt registered [ 8690.006301] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8690.342370] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8690.547721] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8690.550628] LNet: Accept secure, port 988 [ 8692.279173] Key type lgssc registered [ 8693.484100] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8703.262739] Lustre: DEBUG MARKER: Iteration 11 [ 8703.656250] LustreError: 304974:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8703.662570] LustreError: 304973:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8703.674098] LustreError: 304974:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [ 8704.920245] Lustre: Mounted lustre-client [ 8706.373111] Lustre: Unmounted lustre-client [ 8709.297856] Key type lgssc unregistered [ 8709.530579] LNet: 305326:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8710.567219] LNet: Removed LNI 192.168.202.14@tcp [ 8711.190724] Key type .llcrypt unregistered [ 8711.198218] Key type ._llcrypt unregistered [ 8711.928947] alg: No test for adler32 (adler32-zlib) [ 8712.728773] Key type ._llcrypt registered [ 8712.730299] Key type .llcrypt registered [ 8712.902987] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8713.185796] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8713.388032] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8713.395708] LNet: Accept secure, port 988 [ 8715.079218] Key type lgssc registered [ 8716.096609] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8726.209914] Lustre: DEBUG MARKER: Iteration 12 [ 8726.615842] LustreError: 306111:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8726.621811] LustreError: 306113:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8726.631212] LustreError: 306111:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [ 8727.865333] Lustre: Mounted lustre-client [ 8729.080574] Lustre: Unmounted lustre-client [ 8731.392695] Key type lgssc unregistered [ 8731.611380] LNet: 306466:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8732.640517] LNet: Removed LNI 192.168.202.14@tcp [ 8733.215622] Key type .llcrypt unregistered [ 8733.219338] Key type ._llcrypt unregistered [ 8734.135905] alg: No test for adler32 (adler32-zlib) [ 8734.906228] Key type ._llcrypt registered [ 8734.908351] Key type .llcrypt registered [ 8735.145759] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8735.521438] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8735.720812] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8735.724918] LNet: Accept secure, port 988 [ 8737.383147] Key type lgssc registered [ 8738.648831] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8749.479657] Lustre: DEBUG MARKER: Iteration 13 [ 8749.961533] LustreError: 307251:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8749.996597] LustreError: 307258:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8750.008714] LustreError: 307251:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4972 [ 8751.225745] Lustre: Mounted lustre-client [ 8752.658127] Lustre: Unmounted lustre-client [ 8755.562796] Key type lgssc unregistered [ 8755.878996] LNet: 307609:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8756.896603] LNet: Removed LNI 192.168.202.14@tcp [ 8757.546304] Key type .llcrypt unregistered [ 8757.552123] Key type ._llcrypt unregistered [ 8758.429372] alg: No test for adler32 (adler32-zlib) [ 8759.238967] Key type ._llcrypt registered [ 8759.242489] Key type .llcrypt registered [ 8759.479148] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8759.768398] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8759.947543] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8759.953378] LNet: Accept secure, port 988 [ 8761.591127] Key type lgssc registered [ 8762.948645] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8775.875774] Lustre: DEBUG MARKER: Iteration 14 [ 8776.345576] LustreError: 308394:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8776.347030] LustreError: 308396:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8776.362320] LustreError: 308394:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [ 8777.796753] Lustre: Mounted lustre-client [ 8780.075915] Lustre: Unmounted lustre-client [ 8783.274800] Key type lgssc unregistered [ 8783.618722] LNet: 308754:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8784.675748] LNet: Removed LNI 192.168.202.14@tcp [ 8785.655838] Key type .llcrypt unregistered [ 8785.659957] Key type ._llcrypt unregistered [ 8786.864860] alg: No test for adler32 (adler32-zlib) [ 8787.616554] Key type ._llcrypt registered [ 8787.618679] Key type .llcrypt registered [ 8787.820182] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8788.113650] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8788.310924] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8788.315625] LNet: Accept secure, port 988 [ 8790.031127] Key type lgssc registered [ 8791.110988] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8802.596933] Lustre: DEBUG MARKER: Iteration 15 [ 8802.901468] LustreError: 309542:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8802.906416] LustreError: 309541:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8802.933356] LustreError: 309542:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4983 [ 8804.196403] Lustre: Mounted lustre-client [ 8805.708570] Lustre: Unmounted lustre-client [ 8808.074529] Key type lgssc unregistered [ 8808.321711] LNet: 309898:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8809.378463] LNet: Removed LNI 192.168.202.14@tcp [ 8810.134213] Key type .llcrypt unregistered [ 8810.136445] Key type ._llcrypt unregistered [ 8810.956489] alg: No test for adler32 (adler32-zlib) [ 8811.723475] Key type ._llcrypt registered [ 8811.726447] Key type .llcrypt registered [ 8812.012666] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8812.380135] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8812.616924] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8812.622530] LNet: Accept secure, port 988 [ 8814.329025] Key type lgssc registered [ 8815.433366] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8824.198380] Lustre: DEBUG MARKER: Iteration 16 [ 8824.601456] LustreError: 310684:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8824.606447] LustreError: 310685:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8824.616559] LustreError: 310684:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4984 [ 8825.886059] Lustre: Mounted lustre-client [ 8827.235674] Lustre: Unmounted lustre-client [ 8829.351489] Key type lgssc unregistered [ 8829.595637] LNet: 311040:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8830.626808] LNet: Removed LNI 192.168.202.14@tcp [ 8831.543920] Key type .llcrypt unregistered [ 8831.553155] Key type ._llcrypt unregistered [ 8832.449100] alg: No test for adler32 (adler32-zlib) [ 8833.260749] Key type ._llcrypt registered [ 8833.262610] Key type .llcrypt registered [ 8833.418619] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8833.646469] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8833.814281] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8833.819682] LNet: Accept secure, port 988 [ 8835.455126] Key type lgssc registered [ 8836.552353] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8847.916438] Lustre: DEBUG MARKER: Iteration 17 [ 8848.326353] LustreError: 311827:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8848.329918] LustreError: 311828:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8848.339899] LustreError: 311827:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [ 8849.589476] Lustre: Mounted lustre-client [ 8850.735338] Lustre: Unmounted lustre-client [ 8852.678949] Key type lgssc unregistered [ 8852.885918] LNet: 312184:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8853.920450] LNet: Removed LNI 192.168.202.14@tcp [ 8854.599645] Key type .llcrypt unregistered [ 8854.601094] Key type ._llcrypt unregistered [ 8855.381231] alg: No test for adler32 (adler32-zlib) [ 8856.144437] Key type ._llcrypt registered [ 8856.146117] Key type .llcrypt registered [ 8856.311842] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8856.581779] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8856.869470] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8856.875483] LNet: Accept secure, port 988 [ 8858.544596] Key type lgssc registered [ 8859.528499] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8869.170968] Lustre: DEBUG MARKER: Iteration 18 [ 8869.498184] LustreError: 312969:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8869.499123] LustreError: 312971:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8869.508534] LustreError: 312969:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4999 [ 8870.758092] Lustre: Mounted lustre-client [ 8872.413830] Lustre: Unmounted lustre-client [ 8875.302328] Key type lgssc unregistered [ 8875.533321] LNet: 313324:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8876.580529] LNet: Removed LNI 192.168.202.14@tcp [ 8877.195328] Key type .llcrypt unregistered [ 8877.197641] Key type ._llcrypt unregistered [ 8877.798519] alg: No test for adler32 (adler32-zlib) [ 8878.556608] Key type ._llcrypt registered [ 8878.558359] Key type .llcrypt registered [ 8878.723309] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8878.970586] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8879.188694] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8879.191725] LNet: Accept secure, port 988 [ 8880.815229] Key type lgssc registered [ 8881.921970] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8892.218726] Lustre: DEBUG MARKER: Iteration 19 [ 8892.512509] LustreError: 314104:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8892.512825] LustreError: 314110:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8892.523366] LustreError: 314104:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4995 [ 8893.714482] Lustre: Mounted lustre-client [ 8893.718617] Lustre: Skipped 1 previous similar message [ 8894.812676] Lustre: Unmounted lustre-client [ 8897.314761] Key type lgssc unregistered [ 8897.568668] LNet: 314457:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8898.595886] LNet: Removed LNI 192.168.202.14@tcp [ 8899.199862] Key type .llcrypt unregistered [ 8899.202331] Key type ._llcrypt unregistered [ 8899.868247] alg: No test for adler32 (adler32-zlib) [ 8900.624426] Key type ._llcrypt registered [ 8900.626284] Key type .llcrypt registered [ 8900.836049] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8901.192087] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8901.398712] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8901.401483] LNet: Accept secure, port 988 [ 8903.103314] Key type lgssc registered [ 8904.082349] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8913.476507] Lustre: DEBUG MARKER: Iteration 20 [ 8913.928103] LustreError: 315239:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8913.935338] LustreError: 315246:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8913.940634] LustreError: 315239:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [ 8915.130123] Lustre: Mounted lustre-client [ 8915.131583] Lustre: Skipped 1 previous similar message [ 8916.744529] Lustre: Unmounted lustre-client [ 8919.441814] Key type lgssc unregistered [ 8919.699095] LNet: 315602:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8920.741205] LNet: Removed LNI 192.168.202.14@tcp [ 8921.505177] Key type .llcrypt unregistered [ 8921.507813] Key type ._llcrypt unregistered [ 8922.611372] alg: No test for adler32 (adler32-zlib) [ 8923.374342] Key type ._llcrypt registered [ 8923.375802] Key type .llcrypt registered [ 8923.526262] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8923.686601] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8923.822537] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8923.834751] LNet: Accept secure, port 988 [ 8925.519260] Key type lgssc registered [ 8927.079828] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8943.074846] Lustre: DEBUG MARKER: Iteration 21 [ 8943.640191] LustreError: 316392:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8943.641770] LustreError: 316393:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8943.667057] LustreError: 316392:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4980 [ 8945.001625] Lustre: Mounted lustre-client [ 8946.422534] Lustre: Unmounted lustre-client [ 8949.486786] Key type lgssc unregistered [ 8949.762401] LNet: 316751:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8950.831621] LNet: Removed LNI 192.168.202.14@tcp [ 8951.527550] Key type .llcrypt unregistered [ 8951.529146] Key type ._llcrypt unregistered [ 8952.032993] alg: No test for adler32 (adler32-zlib) [ 8952.784799] Key type ._llcrypt registered [ 8952.786827] Key type .llcrypt registered [ 8952.939848] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8953.071643] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8953.218738] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8953.224786] LNet: Accept secure, port 988 [ 8954.903131] Key type lgssc registered [ 8955.966428] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8966.035969] Lustre: DEBUG MARKER: Iteration 22 [ 8966.495042] LustreError: 317535:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8966.509129] LustreError: 317543:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8966.512572] LustreError: 317535:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [ 8967.753112] Lustre: Mounted lustre-client [ 8968.689142] Lustre: Unmounted lustre-client [ 8971.148411] Key type lgssc unregistered [ 8971.333560] LNet: 317896:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8972.387054] LNet: Removed LNI 192.168.202.14@tcp [ 8973.023458] Key type .llcrypt unregistered [ 8973.029295] Key type ._llcrypt unregistered [ 8974.199230] alg: No test for adler32 (adler32-zlib) [ 8974.956602] Key type ._llcrypt registered [ 8974.959924] Key type .llcrypt registered [ 8975.208883] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8975.511935] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8975.772396] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8975.781687] LNet: Accept secure, port 988 [ 8977.527517] Key type lgssc registered [ 8978.566771] Lustre: Echo OBD driver; http://www.lustre.org/ [ 8989.271178] Lustre: DEBUG MARKER: Iteration 23 [ 8989.594244] LustreError: 318681:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 8989.594257] LustreError: 318682:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 8989.603458] LustreError: 318681:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4996 [ 8990.802255] Lustre: Mounted lustre-client [ 8991.827156] Lustre: Unmounted lustre-client [ 8993.969690] Key type lgssc unregistered [ 8994.224130] LNet: 319036:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8995.232438] LNet: Removed LNI 192.168.202.14@tcp [ 8995.810470] Key type .llcrypt unregistered [ 8995.813745] Key type ._llcrypt unregistered [ 8996.660962] alg: No test for adler32 (adler32-zlib) [ 8997.419467] Key type ._llcrypt registered [ 8997.422473] Key type .llcrypt registered [ 8997.612608] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 8997.866201] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 8998.047583] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 8998.051959] LNet: Accept secure, port 988 [ 8999.705235] Key type lgssc registered [ 9000.659533] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9010.044384] Lustre: DEBUG MARKER: Iteration 24 [ 9010.453826] LustreError: 319821:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9010.455961] LustreError: 319822:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9010.468332] LustreError: 319821:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [ 9011.693771] Lustre: Mounted lustre-client [ 9012.702858] Lustre: Unmounted lustre-client [ 9015.155392] Key type lgssc unregistered [ 9015.369025] LNet: 320180:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9016.417652] LNet: Removed LNI 192.168.202.14@tcp [ 9017.214375] Key type .llcrypt unregistered [ 9017.219655] Key type ._llcrypt unregistered [ 9018.157096] alg: No test for adler32 (adler32-zlib) [ 9018.932857] Key type ._llcrypt registered [ 9018.935543] Key type .llcrypt registered [ 9019.164607] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9019.406069] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9019.585381] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9019.589835] LNet: Accept secure, port 988 [ 9021.255107] Key type lgssc registered [ 9022.097479] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9031.888461] Lustre: DEBUG MARKER: Iteration 25 [ 9032.152661] LustreError: 320962:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9032.168930] LustreError: 320972:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9032.172955] LustreError: 320962:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [ 9033.498921] Lustre: Mounted lustre-client [ 9034.830196] Lustre: Unmounted lustre-client [ 9037.133350] Key type lgssc unregistered [ 9037.359761] LNet: 321326:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9038.433298] LNet: Removed LNI 192.168.202.14@tcp [ 9039.101566] Key type .llcrypt unregistered [ 9039.103613] Key type ._llcrypt unregistered [ 9039.880695] alg: No test for adler32 (adler32-zlib) [ 9040.645622] Key type ._llcrypt registered [ 9040.657157] Key type .llcrypt registered [ 9040.878722] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9041.156769] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9041.349351] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9041.352292] LNet: Accept secure, port 988 [ 9043.008703] Key type lgssc registered [ 9044.037088] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9053.397876] Lustre: DEBUG MARKER: Iteration 26 [ 9053.622209] LustreError: 322108:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9053.628517] LustreError: 322112:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9053.633927] LustreError: 322108:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4997 [ 9054.872970] Lustre: Mounted lustre-client [ 9056.234078] Lustre: Unmounted lustre-client [ 9058.012982] Key type lgssc unregistered [ 9058.265802] LNet: 322467:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9059.297026] LNet: Removed LNI 192.168.202.14@tcp [ 9059.835643] Key type .llcrypt unregistered [ 9059.837932] Key type ._llcrypt unregistered [ 9060.572820] alg: No test for adler32 (adler32-zlib) [ 9061.324364] Key type ._llcrypt registered [ 9061.330268] Key type .llcrypt registered [ 9061.549458] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9061.824220] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9062.005397] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9062.008812] LNet: Accept secure, port 988 [ 9063.687459] Key type lgssc registered [ 9065.010118] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9078.849246] Lustre: DEBUG MARKER: Iteration 27 [ 9079.263457] LustreError: 323253:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9079.269792] LustreError: 323255:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9079.293978] LustreError: 323253:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4983 [ 9080.744081] Lustre: Mounted lustre-client [ 9080.757367] Lustre: Skipped 1 previous similar message [ 9082.606041] Lustre: Unmounted lustre-client [ 9085.272480] Key type lgssc unregistered [ 9085.485419] LNet: 323611:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9086.495966] LNet: Removed LNI 192.168.202.14@tcp [ 9087.110667] Key type .llcrypt unregistered [ 9087.112729] Key type ._llcrypt unregistered [ 9088.155778] alg: No test for adler32 (adler32-zlib) [ 9088.912389] Key type ._llcrypt registered [ 9088.914215] Key type .llcrypt registered [ 9089.083770] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9089.307682] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9089.525381] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9089.531738] LNet: Accept secure, port 988 [ 9091.175193] Key type lgssc registered [ 9092.224961] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9103.113912] Lustre: DEBUG MARKER: Iteration 28 [ 9103.724495] LustreError: 324398:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9103.726035] LustreError: 324399:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9103.754493] LustreError: 324398:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4978 [ 9105.069288] Lustre: Mounted lustre-client [ 9105.082136] Lustre: Skipped 1 previous similar message [ 9106.369778] Lustre: Unmounted lustre-client [ 9109.158980] Key type lgssc unregistered [ 9109.365977] LNet: 324753:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9110.434525] LNet: Removed LNI 192.168.202.14@tcp [ 9111.189802] Key type .llcrypt unregistered [ 9111.192830] Key type ._llcrypt unregistered [ 9111.914960] alg: No test for adler32 (adler32-zlib) [ 9112.750495] Key type ._llcrypt registered [ 9112.752655] Key type .llcrypt registered [ 9112.986396] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9113.328549] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9113.525992] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9113.530286] LNet: Accept secure, port 988 [ 9115.255802] Key type lgssc registered [ 9116.611408] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9127.815835] Lustre: DEBUG MARKER: Iteration 29 [ 9128.084607] LustreError: 325536:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9128.084628] LustreError: 325538:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9128.105563] LustreError: 325536:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [ 9129.399693] Lustre: Mounted lustre-client [ 9129.401289] Lustre: Skipped 1 previous similar message [ 9130.770486] Lustre: Unmounted lustre-client [ 9133.400826] Key type lgssc unregistered [ 9133.641283] LNet: 325891:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9134.691932] LNet: Removed LNI 192.168.202.14@tcp [ 9135.390616] Key type .llcrypt unregistered [ 9135.393316] Key type ._llcrypt unregistered [ 9136.338158] alg: No test for adler32 (adler32-zlib) [ 9137.091581] Key type ._llcrypt registered [ 9137.094518] Key type .llcrypt registered [ 9137.234564] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9137.475744] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9137.644802] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9137.648658] LNet: Accept secure, port 988 [ 9139.351575] Key type lgssc registered [ 9140.576778] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9152.421908] Lustre: DEBUG MARKER: Iteration 30 [ 9152.805339] LustreError: 326678:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9152.806822] LustreError: 326679:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9152.815576] LustreError: 326678:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4997 [ 9154.082415] Lustre: Mounted lustre-client [ 9155.373386] Lustre: Unmounted lustre-client [ 9158.403565] Key type lgssc unregistered [ 9158.697575] LNet: 327034:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9159.724318] LNet: Removed LNI 192.168.202.14@tcp [ 9160.603960] Key type .llcrypt unregistered [ 9160.611699] Key type ._llcrypt unregistered [ 9161.591103] alg: No test for adler32 (adler32-zlib) [ 9162.367929] Key type ._llcrypt registered [ 9162.377942] Key type .llcrypt registered [ 9162.600828] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9162.974138] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9163.285155] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9163.296793] LNet: Accept secure, port 988 [ 9165.011041] Key type lgssc registered [ 9166.118242] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9178.226096] Lustre: DEBUG MARKER: Iteration 31 [ 9178.509266] LustreError: 327814:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9178.516133] LustreError: 327821:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9178.531022] LustreError: 327814:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [ 9179.815797] Lustre: Mounted lustre-client [ 9181.584411] Lustre: Unmounted lustre-client [ 9184.765810] Key type lgssc unregistered [ 9185.202541] LNet: 328175:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9186.273612] LNet: Removed LNI 192.168.202.14@tcp [ 9187.202619] Key type .llcrypt unregistered [ 9187.206297] Key type ._llcrypt unregistered [ 9188.388092] alg: No test for adler32 (adler32-zlib) [ 9189.149400] Key type ._llcrypt registered [ 9189.154481] Key type .llcrypt registered [ 9189.437457] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9189.843747] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9190.147178] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9190.153456] LNet: Accept secure, port 988 [ 9191.871591] Key type lgssc registered [ 9193.181397] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9207.263825] Lustre: DEBUG MARKER: Iteration 32 [ 9207.803882] LustreError: 328958:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9207.851912] LustreError: 328970:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9207.857075] LustreError: 328958:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4942 [ 9209.290620] Lustre: Mounted lustre-client [ 9211.237713] Lustre: Unmounted lustre-client [ 9215.720609] Key type lgssc unregistered [ 9216.032402] LNet: 329313:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9217.069816] LNet: Removed LNI 192.168.202.14@tcp [ 9217.888227] Key type .llcrypt unregistered [ 9217.890677] Key type ._llcrypt unregistered [ 9218.845123] alg: No test for adler32 (adler32-zlib) [ 9219.623928] Key type ._llcrypt registered [ 9219.632076] Key type .llcrypt registered [ 9219.952267] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9220.289585] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9220.549605] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9220.560329] LNet: Accept secure, port 988 [ 9222.215180] Key type lgssc registered [ 9223.490201] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9235.845856] Lustre: DEBUG MARKER: Iteration 33 [ 9236.116222] LustreError: 330096:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9236.116692] LustreError: 330098:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9236.128284] LustreError: 330096:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [ 9237.427043] Lustre: Mounted lustre-client [ 9239.261654] Lustre: Unmounted lustre-client [ 9242.997372] Key type lgssc unregistered [ 9243.288214] LNet: 330454:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9244.320608] LNet: Removed LNI 192.168.202.14@tcp [ 9245.223750] Key type .llcrypt unregistered [ 9245.225875] Key type ._llcrypt unregistered [ 9246.430229] alg: No test for adler32 (adler32-zlib) [ 9247.213630] Key type ._llcrypt registered [ 9247.215860] Key type .llcrypt registered [ 9247.428445] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9247.706363] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9247.953150] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9247.961820] LNet: Accept secure, port 988 [ 9249.615189] Key type lgssc registered [ 9250.945109] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9262.328911] Lustre: DEBUG MARKER: Iteration 34 [ 9262.854771] LustreError: 331240:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9262.861118] LustreError: 331239:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9262.876744] LustreError: 331240:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [ 9264.197849] Lustre: Mounted lustre-client [ 9264.203661] Lustre: Skipped 1 previous similar message [ 9265.720684] Lustre: Unmounted lustre-client [ 9268.555875] Key type lgssc unregistered [ 9268.872093] LNet: 331597:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9269.934393] LNet: Removed LNI 192.168.202.14@tcp [ 9270.590216] Key type .llcrypt unregistered [ 9270.592358] Key type ._llcrypt unregistered [ 9271.543730] alg: No test for adler32 (adler32-zlib) [ 9272.297719] Key type ._llcrypt registered [ 9272.300605] Key type .llcrypt registered [ 9272.473405] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9272.871379] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9273.149598] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9273.160313] LNet: Accept secure, port 988 [ 9274.919698] Key type lgssc registered [ 9276.213785] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9287.810713] Lustre: DEBUG MARKER: Iteration 35 [ 9288.161510] LustreError: 332383:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9288.175820] LustreError: 332386:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9288.187542] LustreError: 332383:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4978 [ 9289.413766] Lustre: Mounted lustre-client [ 9291.022204] Lustre: Unmounted lustre-client [ 9293.621467] Key type lgssc unregistered [ 9293.852915] LNet: 332741:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9294.881383] LNet: Removed LNI 192.168.202.14@tcp [ 9295.460412] Key type .llcrypt unregistered [ 9295.462880] Key type ._llcrypt unregistered [ 9296.416626] alg: No test for adler32 (adler32-zlib) [ 9297.183637] Key type ._llcrypt registered [ 9297.190475] Key type .llcrypt registered [ 9297.357286] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9297.654106] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9297.868655] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9297.871945] LNet: Accept secure, port 988 [ 9299.583147] Key type lgssc registered [ 9300.954476] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9311.901338] Lustre: DEBUG MARKER: Iteration 36 [ 9312.223941] LustreError: 333525:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9312.231728] LustreError: 333526:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9312.248865] LustreError: 333525:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4977 [ 9313.500287] Lustre: Mounted lustre-client [ 9315.309879] Lustre: Unmounted lustre-client [ 9318.634962] Key type lgssc unregistered [ 9318.900111] LNet: 333878:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9319.988246] LNet: Removed LNI 192.168.202.14@tcp [ 9320.748935] Key type .llcrypt unregistered [ 9320.763704] Key type ._llcrypt unregistered [ 9321.715081] alg: No test for adler32 (adler32-zlib) [ 9322.520695] Key type ._llcrypt registered [ 9322.524670] Key type .llcrypt registered [ 9322.756603] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9323.126829] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9323.374384] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9323.381326] LNet: Accept secure, port 988 [ 9325.117920] Key type lgssc registered [ 9326.771904] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9340.044691] Lustre: DEBUG MARKER: Iteration 37 [ 9340.554828] LustreError: 334664:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9340.556158] LustreError: 334665:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9340.574926] LustreError: 334664:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [ 9341.901321] Lustre: Mounted lustre-client [ 9341.915367] Lustre: Skipped 1 previous similar message [ 9343.388202] Lustre: Unmounted lustre-client [ 9346.451925] Key type lgssc unregistered [ 9346.763656] LNet: 335020:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9347.809487] LNet: Removed LNI 192.168.202.14@tcp [ 9348.672671] Key type .llcrypt unregistered [ 9348.674983] Key type ._llcrypt unregistered [ 9349.563243] alg: No test for adler32 (adler32-zlib) [ 9350.339594] Key type ._llcrypt registered [ 9350.345273] Key type .llcrypt registered [ 9350.540985] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9350.855465] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9351.151397] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9351.155665] LNet: Accept secure, port 988 [ 9352.847186] Key type lgssc registered [ 9353.824649] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9365.176796] Lustre: DEBUG MARKER: Iteration 38 [ 9365.430810] LustreError: 335801:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9365.430936] LustreError: 335804:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9365.445178] LustreError: 335801:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [ 9366.641796] Lustre: Mounted lustre-client [ 9368.149914] Lustre: Unmounted lustre-client [ 9370.687535] Key type lgssc unregistered [ 9370.943931] LNet: 336157:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9372.018298] LNet: Removed LNI 192.168.202.14@tcp [ 9372.601496] Key type .llcrypt unregistered [ 9372.603809] Key type ._llcrypt unregistered [ 9373.268856] alg: No test for adler32 (adler32-zlib) [ 9374.043194] Key type ._llcrypt registered [ 9374.045818] Key type .llcrypt registered [ 9374.216317] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9374.495250] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9374.702459] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9374.712872] LNet: Accept secure, port 988 [ 9376.408320] Key type lgssc registered [ 9377.534849] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9388.701904] Lustre: DEBUG MARKER: Iteration 39 [ 9389.288526] LustreError: 336944:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9389.289796] LustreError: 336943:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9389.304680] LustreError: 336944:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [ 9390.551936] Lustre: Mounted lustre-client [ 9390.564522] Lustre: Skipped 1 previous similar message [ 9391.805268] Lustre: Unmounted lustre-client [ 9394.167744] Key type lgssc unregistered [ 9394.389625] LNet: 337299:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9395.430982] LNet: Removed LNI 192.168.202.14@tcp [ 9396.246145] Key type .llcrypt unregistered [ 9396.248799] Key type ._llcrypt unregistered [ 9397.336558] alg: No test for adler32 (adler32-zlib) [ 9398.096436] Key type ._llcrypt registered [ 9398.100548] Key type .llcrypt registered [ 9398.433171] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9398.879767] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9399.070092] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9399.074555] LNet: Accept secure, port 988 [ 9400.755331] Key type lgssc registered [ 9402.138571] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9413.221567] Lustre: DEBUG MARKER: Iteration 40 [ 9413.712256] LustreError: 338085:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9413.715157] LustreError: 338086:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9413.734189] LustreError: 338085:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [ 9415.031764] Lustre: Mounted lustre-client [ 9415.036899] Lustre: Skipped 1 previous similar message [ 9416.412055] Lustre: Unmounted lustre-client [ 9419.266726] Key type lgssc unregistered [ 9419.477890] LNet: 338444:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9420.516891] LNet: Removed LNI 192.168.202.14@tcp [ 9421.298993] Key type .llcrypt unregistered [ 9421.301238] Key type ._llcrypt unregistered [ 9422.341030] alg: No test for adler32 (adler32-zlib) [ 9423.124526] Key type ._llcrypt registered [ 9423.126472] Key type .llcrypt registered [ 9423.288251] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9423.573427] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9423.793580] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9423.799869] LNet: Accept secure, port 988 [ 9425.447133] Key type lgssc registered [ 9426.514897] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9436.455192] Lustre: DEBUG MARKER: Iteration 41 [ 9436.773846] LustreError: 339229:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9436.774341] LustreError: 339230:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9436.794699] LustreError: 339229:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4983 [ 9438.009766] Lustre: Mounted lustre-client [ 9438.014764] Lustre: Skipped 1 previous similar message [ 9439.455281] Lustre: Unmounted lustre-client [ 9441.962130] Key type lgssc unregistered [ 9442.182394] LNet: 339585:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9443.234664] LNet: Removed LNI 192.168.202.14@tcp [ 9443.813040] Key type .llcrypt unregistered [ 9443.815134] Key type ._llcrypt unregistered [ 9444.595534] alg: No test for adler32 (adler32-zlib) [ 9445.395361] Key type ._llcrypt registered [ 9445.397468] Key type .llcrypt registered [ 9445.585458] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9445.916419] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9446.057820] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9446.060216] LNet: Accept secure, port 988 [ 9447.695400] Key type lgssc registered [ 9448.835775] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9460.018618] Lustre: DEBUG MARKER: Iteration 42 [ 9460.452218] LustreError: 340373:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9460.453072] LustreError: 340374:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9460.474236] LustreError: 340373:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [ 9461.761297] Lustre: Mounted lustre-client [ 9461.763953] Lustre: Skipped 1 previous similar message [ 9463.451817] Lustre: Unmounted lustre-client [ 9465.865982] Key type lgssc unregistered [ 9466.043786] LNet: 340731:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9467.103957] LNet: Removed LNI 192.168.202.14@tcp [ 9467.741420] Key type .llcrypt unregistered [ 9467.742993] Key type ._llcrypt unregistered [ 9468.762280] alg: No test for adler32 (adler32-zlib) [ 9469.529656] Key type ._llcrypt registered [ 9469.532658] Key type .llcrypt registered [ 9469.755424] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9470.085337] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9470.270209] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9470.274431] LNet: Accept secure, port 988 [ 9471.919178] Key type lgssc registered [ 9472.836774] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9484.473485] Lustre: DEBUG MARKER: Iteration 43 [ 9484.840160] LustreError: 341519:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9484.842079] LustreError: 341517:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9484.858364] LustreError: 341519:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [ 9486.143203] Lustre: Mounted lustre-client [ 9487.628968] Lustre: Unmounted lustre-client [ 9490.399965] Key type lgssc unregistered [ 9490.655092] LNet: 341870:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9491.679684] LNet: Removed LNI 192.168.202.14@tcp [ 9492.204580] Key type .llcrypt unregistered [ 9492.209987] Key type ._llcrypt unregistered [ 9493.053033] alg: No test for adler32 (adler32-zlib) [ 9493.821682] Key type ._llcrypt registered [ 9493.823022] Key type .llcrypt registered [ 9494.085160] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9494.399439] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9494.576782] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9494.579892] LNet: Accept secure, port 988 [ 9496.231128] Key type lgssc registered [ 9497.338835] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9509.317099] Lustre: DEBUG MARKER: Iteration 44 [ 9509.831498] LustreError: 342655:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9509.832839] LustreError: 342656:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9509.857885] LustreError: 342655:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4979 [ 9511.134152] Lustre: Mounted lustre-client [ 9512.649339] Lustre: Unmounted lustre-client [ 9515.264492] Key type lgssc unregistered [ 9515.537199] LNet: 343013:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9516.576476] LNet: Removed LNI 192.168.202.14@tcp [ 9517.323205] Key type .llcrypt unregistered [ 9517.325176] Key type ._llcrypt unregistered [ 9518.099211] alg: No test for adler32 (adler32-zlib) [ 9518.886534] Key type ._llcrypt registered [ 9518.888252] Key type .llcrypt registered [ 9519.091861] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9519.383723] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9519.701251] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9519.714036] LNet: Accept secure, port 988 [ 9521.455196] Key type lgssc registered [ 9522.567971] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9533.164640] Lustre: DEBUG MARKER: Iteration 45 [ 9533.549082] LustreError: 343800:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9533.549929] LustreError: 343799:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9533.563795] LustreError: 343800:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [ 9534.849286] Lustre: Mounted lustre-client [ 9534.852943] Lustre: Skipped 1 previous similar message [ 9536.119478] Lustre: Unmounted lustre-client [ 9538.688912] Key type lgssc unregistered [ 9538.998337] LNet: 344156:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9540.079242] LNet: Removed LNI 192.168.202.14@tcp [ 9540.992651] Key type .llcrypt unregistered [ 9540.997273] Key type ._llcrypt unregistered [ 9541.841990] alg: No test for adler32 (adler32-zlib) [ 9542.635071] Key type ._llcrypt registered [ 9542.644087] Key type .llcrypt registered [ 9542.960702] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9543.383321] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9543.698091] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9543.703972] LNet: Accept secure, port 988 [ 9545.447641] Key type lgssc registered [ 9546.798309] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9559.084315] Lustre: DEBUG MARKER: Iteration 46 [ 9559.493443] LustreError: 344943:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9559.494115] LustreError: 344944:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9559.512428] LustreError: 344943:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4982 [ 9560.802914] Lustre: Mounted lustre-client [ 9560.810509] Lustre: Skipped 1 previous similar message [ 9563.401115] Lustre: Unmounted lustre-client [ 9566.786957] Key type lgssc unregistered [ 9567.198690] LNet: 345301:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9568.227406] LNet: Removed LNI 192.168.202.14@tcp [ 9569.180500] Key type .llcrypt unregistered [ 9569.189960] Key type ._llcrypt unregistered [ 9570.532107] alg: No test for adler32 (adler32-zlib) [ 9571.302958] Key type ._llcrypt registered [ 9571.305501] Key type .llcrypt registered [ 9571.662569] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9572.207809] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9572.539025] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9572.548169] LNet: Accept secure, port 988 [ 9574.295218] Key type lgssc registered [ 9575.605772] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9586.233258] Lustre: DEBUG MARKER: Iteration 47 [ 9586.541874] LustreError: 346087:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9586.542092] LustreError: 346086:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9586.563484] LustreError: 346087:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [ 9587.773985] Lustre: Mounted lustre-client [ 9589.080660] Lustre: Unmounted lustre-client [ 9591.855366] Key type lgssc unregistered [ 9592.044796] LNet: 346442:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9593.063375] LNet: Removed LNI 192.168.202.14@tcp [ 9593.643667] Key type .llcrypt unregistered [ 9593.646517] Key type ._llcrypt unregistered [ 9594.534886] alg: No test for adler32 (adler32-zlib) [ 9595.294186] Key type ._llcrypt registered [ 9595.296460] Key type .llcrypt registered [ 9595.452378] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9595.746248] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9595.974258] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9595.977501] LNet: Accept secure, port 988 [ 9597.687126] Key type lgssc registered [ 9598.740313] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9608.041767] Lustre: DEBUG MARKER: Iteration 48 [ 9608.431021] LustreError: 347227:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9608.433606] LustreError: 347228:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9608.454105] LustreError: 347227:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4984 [ 9609.729870] Lustre: Mounted lustre-client [ 9610.918890] Lustre: Unmounted lustre-client [ 9612.832460] Key type lgssc unregistered [ 9613.069583] LNet: 347583:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9614.113359] LNet: Removed LNI 192.168.202.14@tcp [ 9614.823987] Key type .llcrypt unregistered [ 9614.826040] Key type ._llcrypt unregistered [ 9615.627975] alg: No test for adler32 (adler32-zlib) [ 9616.390565] Key type ._llcrypt registered [ 9616.392441] Key type .llcrypt registered [ 9616.633763] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9617.075575] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9617.382159] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9617.390493] LNet: Accept secure, port 988 [ 9619.135180] Key type lgssc registered [ 9620.710589] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9632.649957] Lustre: DEBUG MARKER: Iteration 49 [ 9633.084891] LustreError: 348371:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9633.100956] LustreError: 348372:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9633.113966] LustreError: 348371:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4977 [ 9634.376303] Lustre: Mounted lustre-client [ 9636.064205] Lustre: Unmounted lustre-client [ 9638.443427] Key type lgssc unregistered [ 9638.708984] LNet: 348729:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9639.778340] LNet: Removed LNI 192.168.202.14@tcp [ 9640.362582] Key type .llcrypt unregistered [ 9640.363850] Key type ._llcrypt unregistered [ 9641.094294] alg: No test for adler32 (adler32-zlib) [ 9641.852401] Key type ._llcrypt registered [ 9641.856576] Key type .llcrypt registered [ 9642.038471] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9642.302678] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9642.446336] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9642.449509] LNet: Accept secure, port 988 [ 9644.087132] Key type lgssc registered [ 9644.989776] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9654.446506] Lustre: DEBUG MARKER: Iteration 50 [ 9654.776835] LustreError: 349515:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [ 9654.784947] LustreError: 349514:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [ 9654.790326] LustreError: 349515:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=5000 [ 9656.024112] Lustre: Mounted lustre-client [ 9656.026550] Lustre: Skipped 1 previous similar message [ 9657.277777] Lustre: Unmounted lustre-client [ 9659.565336] Key type lgssc unregistered [ 9659.791031] LNet: 349871:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9660.835145] LNet: Removed LNI 192.168.202.14@tcp [ 9661.413988] Key type .llcrypt unregistered [ 9661.415449] Key type ._llcrypt unregistered [ 9662.101424] alg: No test for adler32 (adler32-zlib) [ 9662.854473] Key type ._llcrypt registered [ 9662.856250] Key type .llcrypt registered [ 9663.076300] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 9663.337426] Lustre: Lustre: Build Version: 2.15.8_11_g8969407 [ 9663.582487] LNet: Added LNI 192.168.202.14@tcp [8/256/0/180] [ 9663.587529] LNet: Accept secure, port 988 [ 9665.247163] Key type lgssc registered [ 9666.414960] Lustre: Echo OBD driver; http://www.lustre.org/ [ 9675.837072] Lustre: Mounted lustre-client [ 9681.734806] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 16:46:30 (1776199590) [ 9690.079139] Lustre: 351177:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776199593/real 1776199593] req@00000000066960bd x1862480244511552/t0(0) o36->lustre-MDT0000-mdc-ffff9039d1f24800@192.168.202.114@tcp:12/10 lens 496/440 e 0 to 1 dl 1776199600 ref 2 fl Rpc:XQr/0/ffffffff rc 0/-1 job:'ln.0' [ 9690.100081] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection to lustre-MDT0000 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9690.120412] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection restored to (at 192.168.202.114@tcp) [ 9697.247856] Lustre: 351177:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776199600/real 1776199600] req@00000000066960bd x1862480244511552/t0(0) o36->lustre-MDT0000-mdc-ffff9039d1f24800@192.168.202.114@tcp:12/10 lens 496/440 e 0 to 1 dl 1776199607 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [ 9697.269925] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection to lustre-MDT0000 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9697.296319] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection restored to (at 192.168.202.114@tcp) [ 9704.415154] Lustre: 351177:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776199607/real 1776199607] req@00000000066960bd x1862480244511552/t0(0) o36->lustre-MDT0000-mdc-ffff9039d1f24800@192.168.202.114@tcp:12/10 lens 496/440 e 0 to 1 dl 1776199614 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [ 9704.440505] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection to lustre-MDT0000 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9704.459597] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection restored to (at 192.168.202.114@tcp) [ 9710.559386] Lustre: 351177:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776199614/real 1776199614] req@00000000066960bd x1862480244511552/t0(0) o36->lustre-MDT0000-mdc-ffff9039d1f24800@192.168.202.114@tcp:12/10 lens 496/440 e 0 to 1 dl 1776199621 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [ 9710.592501] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection to lustre-MDT0000 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9710.638460] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection restored to (at 192.168.202.114@tcp) [ 9717.727243] Lustre: 351177:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776199621/real 1776199621] req@00000000066960bd x1862480244511552/t0(0) o36->lustre-MDT0000-mdc-ffff9039d1f24800@192.168.202.114@tcp:12/10 lens 496/440 e 0 to 1 dl 1776199628 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [ 9717.752076] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection to lustre-MDT0000 (at 192.168.202.114@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 9717.807441] Lustre: lustre-MDT0000-mdc-ffff9039d1f24800: Connection restored to (at 192.168.202.114@tcp) [ 9724.706972] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 16:47:13 (1776199633) [ 9726.422965] Lustre: DEBUG MARKER: SKIP: sanityn test_111 needs >= 2 MDTs [ 9728.444450] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 16:47:17 (1776199637) [ 9730.039851] Lustre: DEBUG MARKER: SKIP: sanityn test_112 We need at least 2 MDTs for this test [ 9731.513810] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 16:47:20 (1776199640) [ 9737.487262] Lustre: DEBUG MARKER: cleanup: ====================================================== [ 9739.281126] Lustre: DEBUG MARKER: == sanityn test complete, duration 9485 sec ============== 16:47:28 (1776199648) [ 9929.511509] Lustre: Unmounted lustre-client [ 9930.961309] Lustre: Unmounted lustre-client [ 9948.258718] Key type lgssc unregistered [ 9948.499213] LNet: 353601:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 9949.544870] LNet: Removed LNI 192.168.202.14@tcp [ 9950.069107] Key type .llcrypt unregistered [ 9950.070187] Key type ._llcrypt unregistered