[ 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 409467093 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: 2895288K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001012] APIC: Switch to symmetric I/O mode setup [ 0.002230] x2apic enabled [ 0.003011] Switched APIC routing to physical x2apic. [ 0.004016] kvm-guest: setup PV IPIs [ 0.006889] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007022] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008013] pid_max: default: 32768 minimum: 301 [ 0.009156] LSM: Security Framework initializing [ 0.010058] Yama: becoming mindful. [ 0.011038] SELinux: Initializing. [ 0.012078] *** VALIDATE selinux *** [ 0.020820] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.025476] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026208] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028022] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029122] *** VALIDATE tmpfs *** [ 0.030520] *** VALIDATE proc *** [ 0.032174] *** VALIDATE cgroup *** [ 0.033010] *** VALIDATE cgroup2 *** [ 0.035058] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.036152] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.037008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.038029] Spectre V2 : User space: Vulnerable [ 0.039008] Speculative Store Bypass: Vulnerable [ 0.042191] debug: unmapping init [mem 0xffffffffaec59000-0xffffffffaec60fff] [ 0.044965] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.045724] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.046024] ... version: 2 [ 0.047016] ... bit width: 48 [ 0.048015] ... generic registers: 4 [ 0.049012] ... value mask: 0000ffffffffffff [ 0.050015] ... max period: 00007fffffffffff [ 0.051015] ... fixed-purpose events: 3 [ 0.052013] ... event mask: 000000070000000f [ 0.053323] rcu: Hierarchical SRCU implementation. [ 0.055435] smp: Bringing up secondary CPUs ... [ 0.056596] x86: Booting SMP configuration: [ 0.057025] .... node #0, CPUs: #1 #2 #3 [ 0.061259] smp: Brought up 1 node, 4 CPUs [ 0.063014] smpboot: Max logical packages: 1 [ 0.064018] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.158032] node 0 deferred pages initialised in 92ms [ 0.161239] devtmpfs: initialized [ 0.162233] x86/mm: Memory block size: 128MB [ 0.164762] gcov: version magic: 0x41383552 [ 0.166195] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.168036] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.169255] pinctrl core: initialized pinctrl subsystem [ 0.170194] [ 0.170678] ************************************************************* [ 0.171017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.172014] ** ** [ 0.173014] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.174015] ** ** [ 0.175012] ** This means that this kernel is built to expose internal ** [ 0.176013] ** IOMMU data structures, which may compromise security on ** [ 0.177016] ** your system. ** [ 0.178013] ** ** [ 0.179013] ** If you see this message and you are not debugging the ** [ 0.180012] ** kernel, report this immediately to your vendor! ** [ 0.181016] ** ** [ 0.182015] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.183013] ************************************************************* [ 0.184726] NET: Registered protocol family 16 [ 0.185476] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.186062] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.187060] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.188482] cpuidle: using governor menu [ 0.190715] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.193718] PCI: Using configuration type 1 for base access [ 0.195158] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.204122] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.205030] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.206166] cryptd: max_cpu_qlen set to 1000 [ 0.208144] ACPI: Added _OSI(Module Device) [ 0.209017] ACPI: Added _OSI(Processor Device) [ 0.210012] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.211015] ACPI: Added _OSI(Processor Aggregator Device) [ 0.215279] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.217766] ACPI: Interpreter enabled [ 0.218072] ACPI: PM: (supports S0 S3 S4 S5) [ 0.219021] ACPI: Using IOAPIC for interrupt routing [ 0.220147] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.221420] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.230594] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.231060] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.232029] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.233112] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.235488] acpiphp: Slot [2] registered [ 0.236159] acpiphp: Slot [5] registered [ 0.237139] acpiphp: Slot [6] registered [ 0.238151] acpiphp: Slot [3] registered [ 0.239146] acpiphp: Slot [4] registered [ 0.240137] acpiphp: Slot [7] registered [ 0.241149] acpiphp: Slot [8] registered [ 0.242175] acpiphp: Slot [9] registered [ 0.243083] acpiphp: Slot [10] registered [ 0.244094] acpiphp: Slot [11] registered [ 0.245103] acpiphp: Slot [12] registered [ 0.246090] acpiphp: Slot [13] registered [ 0.247078] acpiphp: Slot [14] registered [ 0.248100] acpiphp: Slot [15] registered [ 0.249118] acpiphp: Slot [16] registered [ 0.250101] acpiphp: Slot [17] registered [ 0.251115] acpiphp: Slot [18] registered [ 0.252094] acpiphp: Slot [19] registered [ 0.253108] acpiphp: Slot [20] registered [ 0.254103] acpiphp: Slot [21] registered [ 0.255147] acpiphp: Slot [22] registered [ 0.256092] acpiphp: Slot [23] registered [ 0.257143] acpiphp: Slot [24] registered [ 0.258132] acpiphp: Slot [25] registered [ 0.259120] acpiphp: Slot [26] registered [ 0.260103] acpiphp: Slot [27] registered [ 0.261051] acpiphp: Slot [28] registered [ 0.263118] acpiphp: Slot [29] registered [ 0.265077] acpiphp: Slot [30] registered [ 0.266000] acpiphp: Slot [31] registered [ 0.266000] PCI host bridge to bus 0000:00 [ 0.268021] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.271025] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.273021] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.276025] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.278019] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.281028] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.282146] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.285048] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.288351] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.296015] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.299044] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.300011] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.302017] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.304017] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.307641] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.309746] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.312057] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.315134] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.318887] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.328019] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.332023] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.337566] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.345027] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.350022] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.363027] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.372920] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.384019] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.393020] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.414019] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.425717] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.427402] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.429442] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.432298] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.433270] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.438223] iommu: Default domain type: Passthrough [ 0.440540] SCSI subsystem initialized [ 0.441118] ACPI: bus type USB registered [ 0.442087] usbcore: registered new interface driver usbfs [ 0.444159] usbcore: registered new interface driver hub [ 0.445111] usbcore: registered new device driver usb [ 0.447128] pps_core: LinuxPPS API ver. 1 registered [ 0.448007] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.450096] PTP clock support registered [ 0.451178] EDAC MC: Ver: 3.0.0 [ 0.453152] PCI: Using ACPI for IRQ routing [ 0.454632] NetLabel: Initializing [ 0.455012] NetLabel: domain hash size = 128 [ 0.456010] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.457122] NetLabel: unlabeled traffic allowed by default [ 0.459226] vgaarb: loaded [ 0.460275] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.461008] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.464398] clocksource: Switched to clocksource kvm-clock [ 0.576428] VFS: Disk quotas dquot_6.6.0 [ 0.577858] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.580169] *** VALIDATE ramfs *** [ 0.581360] *** VALIDATE hugetlbfs *** [ 0.582942] pnp: PnP ACPI init [ 0.585403] pnp: PnP ACPI: found 6 devices [ 0.605843] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.608330] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.610551] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.612466] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.614710] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.616900] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.619433] NET: Registered protocol family 2 [ 0.621632] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.625972] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.629246] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.633833] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.636314] TCP: Hash tables configured (established 65536 bind 65536) [ 0.638517] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.640447] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.642467] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.644041] NET: Registered protocol family 1 [ 0.645485] RPC: Registered named UNIX socket transport module. [ 0.647603] RPC: Registered udp transport module. [ 0.649645] RPC: Registered tcp transport module. [ 0.651537] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.654048] NET: Registered protocol family 44 [ 0.656398] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.658926] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.661084] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.663094] PCI: CLS 0 bytes, default 64 [ 0.664580] Unpacking initramfs... [ 2.054382] debug: unmapping init [mem 0xffff93eb7cc64000-0xffff93eb7ffcffff] [ 2.057612] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.059800] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.062613] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.581097] Initialise system trusted keyrings [ 2.582495] Key type blacklist registered [ 2.584148] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.592741] zbud: loaded [ 2.597506] *** VALIDATE nfs *** [ 2.599209] *** VALIDATE nfs4 *** [ 2.601349] pstore: using deflate compression [ 2.605887] Platform Keyring initialized [ 2.709306] NET: Registered protocol family 38 [ 2.711081] Key type asymmetric registered [ 2.712750] Asymmetric key parser 'x509' registered [ 2.714562] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.717435] io scheduler mq-deadline registered [ 2.718972] io scheduler kyber registered [ 2.720567] io scheduler bfq registered [ 2.722819] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.725726] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.729192] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.732413] ACPI: Power Button [PWRF] [ 2.739774] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.746625] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.757377] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.785632] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.817928] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.822193] Non-volatile memory driver v1.3 [ 2.823840] Linux agpgart interface v0.103 [ 2.855260] virtio_blk virtio1: [vda] 68000 512-byte logical blocks (34.8 MB/33.2 MiB) [ 2.859250] vda: detected capacity change from 0 to 34816000 [ 2.873479] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 2.876066] vdb: detected capacity change from 0 to 1073741824 [ 2.881972] libphy: Fixed MDIO Bus: probed [ 2.887879] usbcore: registered new interface driver usbserial_generic [ 2.889774] usbserial: USB Serial support registered for generic [ 2.891508] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 2.895065] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 2.896456] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 2.898505] mousedev: PS/2 mouse device common for all mice [ 2.901784] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 2.903533] rtc_cmos 00:05: RTC can wake from S4 [ 2.907938] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 2.908243] rtc_cmos 00:05: registered as rtc0 [ 2.913507] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 2.913518] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 2.918343] intel_pstate: CPU model not supported [ 2.920620] hid: raw HID events driver (C) Jiri Kosina [ 2.923137] usbcore: registered new interface driver usbhid [ 2.925127] usbhid: USB HID core driver [ 2.926820] drop_monitor: Initializing network drop monitor service [ 2.929615] Initializing XFRM netlink socket [ 2.931695] NET: Registered protocol family 10 [ 2.934195] Segment Routing with IPv6 [ 2.935389] NET: Registered protocol family 17 [ 2.937039] mpls_gso: MPLS GSO support [ 2.943675] RAS: Correctable Errors collector initialized. [ 2.945744] AVX version of gcm_enc/dec engaged. [ 2.947032] AES CTR mode by8 optimization enabled [ 3.020874] sched_clock: Marking stable (3020851690, 0)->(3935067224, -914215534) [ 3.023815] registered taskstats version 1 [ 3.025484] Loading compiled-in X.509 certificates [ 3.027915] zswap: loaded using pool lzo/zbud [ 3.049428] Key type big_key registered [ 3.061593] Key type encrypted registered [ 3.063295] ima: No TPM chip found, activating TPM-bypass! [ 3.065188] ima: Allocated hash algorithm: sha1 [ 3.066860] ima: No architecture policies found [ 3.068599] evm: Initialising EVM extended attributes: [ 3.070243] evm: security.selinux [ 3.071440] evm: security.ima [ 3.072511] evm: security.capability [ 3.073804] evm: HMAC attrs: 0x1 [ 3.076129] rtc_cmos 00:05: setting system clock to 2026-04-14 21:14:34 UTC (1776201274) [ 3.081332] debug: unmapping init [mem 0xffffffffafc03000-0xffffffffafdfffff] [ 3.083817] debug: unmapping init [mem 0xffffffffae982000-0xffffffffaec58fff] [ 3.090076] Write protecting the kernel read-only data: 28672k [ 3.093525] debug: unmapping init [mem 0xffffffffad003000-0xffffffffad1fffff] [ 3.096400] debug: unmapping init [mem 0xffffffffad914000-0xffffffffad9fffff] [ 3.125524] 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.130768] systemd[1]: Detected virtualization kvm. [ 3.131983] systemd[1]: Detected architecture x86-64. [ 3.133538] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.160575] systemd[1]: No hostname configured. [ 3.162161] systemd[1]: Set hostname to . [ 3.164060] random: systemd: uninitialized urandom read (16 bytes read) [ 3.166390] systemd[1]: Initializing machine ID from random generator. [ 3.207055] random: ln: uninitialized urandom read (6 bytes read) [ 3.286705] random: systemd: uninitialized urandom read (16 bytes read) [ 3.289539] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 3.294672] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 3.298207] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket. Starting Journal Service... Starting Apply Kernel Variables... [ OK ] Started Memstrack Anylazing Service. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Paths. [ OK ] Reached target Slices. [ OK ] Reached target Initrd Root Device. Starting Setup Virtual Console... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Sockets. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 3.820196] device-mapper: uevent: version 1.0.3 [ 3.821696] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 4.448521] virtio_net virtio0 ens2: renamed from eth0 [ 4.483625] random: fast init done [ 4.513068] scsi host0: ata_piix [ 4.519079] scsi host1: ata_piix [ 4.520471] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 4.522494] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 8.807429] dracut-initqueue[589]: RTNETLINK answers: File exists [ 9.578105] random: crng init done [ 9.579520] 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... [ 10.330936] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. Stopping Hardware RNG Entropy Gatherer Daemon... [ 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 Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Swap. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.444557] printk: systemd: 24 output lines suppressed due to ratelimiting [ 11.690635] SELinux: Disabled at runtime. [ 11.752629] 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.760966] systemd[1]: Detected virtualization kvm. [ 11.762605] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.180283] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.183396] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.188366] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.191809] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.194853] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.203177] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.206437] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Created slice User and Session Slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. Activating swap /dev/disk/by-label/SWAP... [ 12.247589] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on Process Core Dump Socket. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting Huge Pages File System... [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting POSIX Message Queue File System... Mounting Kernel Debug File System... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. Starting Remount Root and Kernel File Systems... [ OK ] Listening on udev Control Socket. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Slices. Starting udev Coldplug all Devices... [ OK ] Created slice system-getty.slice. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Starting Apply Kernel Variables... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Stopped target Initrd Root File System. [ OK ] Reached target rpc_pipefs.target. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Journal Service. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Kernel Debug File System. [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 ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 12.661870] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 12.976293] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 12.988197] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.097814] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.108507] EDAC sbridge: Ver: 1.1.2 [ 14.011515] Key type dns_resolver registered [ 14.312505] NFS: Registering the id_resolver key type [ 14.314460] Key type id_resolver registered [ 14.315953] 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 Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Login Service... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Restore /run/initramfs on shutdown... [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting Network Manager Wait Online... [ OK ] Started OpenSSH server daemon. Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ 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 Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg235-client login: [ 34.534975] hrtimer: interrupt took 7286455 ns [ 50.284993] libcfs: loading out-of-tree module taints kernel. [ 50.450077] alg: No test for adler32 (adler32-zlib) [ 51.220321] Key type ._llcrypt registered [ 51.226501] Key type .llcrypt registered [ 51.630819] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 52.365774] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [ 53.395761] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [ 53.404080] LNet: Accept secure, port 988 [ 55.311281] Key type lgssc registered [ 57.409184] Lustre: Echo OBD driver; http://www.lustre.org/ [ 214.484599] Lustre: Mounted lustre-client [ 219.109595] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 234.366970] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing check_logdir /tmp/testlogs/ [ 240.103411] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 23s idle [ 240.373371] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing yml_node [ 244.930321] Lustre: DEBUG MARKER: Client: 2.15.8.1 [ 247.569120] Lustre: DEBUG MARKER: MDS: 2.15.8.1 [ 250.728662] Lustre: DEBUG MARKER: OSS: 2.15.8.1 [ 252.849657] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Tue Apr 14 17:18:42 EDT 2026 [ 265.657537] Lustre: DEBUG MARKER: excepting tests: 27 28 [ 268.114607] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 269.045096] Lustre: Mounted lustre-client [ 274.949149] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing check_config_client /mnt/lustre [ 293.139539] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 308.649362] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 17:19:37 (1776201577) [ 317.099554] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 17:19:47 (1776201587) [ 324.376233] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 17:19:54 (1776201594) [ 331.217814] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 17:20:01 (1776201601) [ 336.588438] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 17:20:06 (1776201606) [ 343.533186] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 17:20:13 (1776201613) [ 349.774348] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 17:20:19 (1776201619) [ 355.078352] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 17:20:25 (1776201625) [ 361.943125] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 17:20:31 (1776201631) [ 368.102060] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 17:20:38 (1776201638) [ 374.955903] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 17:20:45 (1776201645) [ 376.815168] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 21s idle [ 376.826409] Lustre: Skipped 1 previous similar message [ 381.329683] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 17:20:51 (1776201651) [ 387.921754] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 17:20:58 (1776201658) [ 392.165567] Lustre: lustre-OST0001-osc-ffff93ebc9842000: disconnect after 23s idle [ 394.015853] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 17:21:03 (1776201663) [ 400.428667] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 17:21:10 (1776201670) [ 406.937156] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 17:21:17 (1776201677) [ 413.714289] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 17:21:23 (1776201683) [ 422.786349] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 17:21:32 (1776201692) [ 429.795128] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 17:21:39 (1776201699) [ 436.952489] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 17:21:46 (1776201706) [ 437.918485] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205289279508 file: /mnt/lustre/lockdir/lockfile=144115205289279507 [ 587.931927] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 17:24:17 (1776201857) [ 594.904865] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 17:24:25 (1776201865) [ 600.967233] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 17:24:31 (1776201871) [ 607.134530] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 17:24:37 (1776201877) [ 614.210566] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 17:24:44 (1776201884) [ 621.260643] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 17:24:51 (1776201891) [ 623.151694] Lustre: DEBUG MARKER: chmod [ 630.707827] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 17:25:00 (1776201900) [ 638.713511] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7207484kB free gt MAXFREE 800000kB, increase 800000 (or reduce test fs size) to proceed [ 650.315038] Lustre: DEBUG MARKER: == sanityn test 16a: 2500 iterations of dual-mount fsx === 17:25:20 (1776201920) [ 952.333547] Lustre: DEBUG MARKER: == sanityn test 16b: 2500 iterations of dual-mount fsx at small size ========================================================== 17:30:22 (1776202222) [ 1079.255207] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 17:32:29 (1776202349) [ 1265.572419] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 17:35:35 (1776202535) [ 1303.904087] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 17:36:13 (1776202573) [ 1308.639478] Lustre: lustre-OST0000-osc-ffff93ebc9842000: disconnect after 24s idle [ 1311.761962] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 17:36:21 (1776202581) [ 1313.460327] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1313.598743] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1313.702960] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1313.798123] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1313.903148] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.041614] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.125706] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.204098] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.308861] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.435835] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.544477] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.630252] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.721766] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.844329] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1314.969664] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1315.066700] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1315.149961] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1315.261169] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1315.449624] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1315.600452] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1315.759820] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1315.950174] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.087519] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.194185] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.277990] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.427961] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.506105] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.658944] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.734875] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.842076] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1316.946066] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.039852] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.127194] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.224521] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.297932] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.385762] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.442727] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.488155] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.549242] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.584266] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.621850] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.672662] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.723497] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.775951] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.841521] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.911244] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1317.983760] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.102078] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.198973] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.285279] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.354818] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.458153] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.546876] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.659321] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.774901] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.892797] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1318.978594] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.071317] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.167906] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.250852] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.348118] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.447148] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.528208] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.614798] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.702386] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.779683] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.846511] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1319.939968] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.024975] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.110528] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.187840] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.271650] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.349197] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.433866] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.515825] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.606677] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.696151] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.778736] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.869780] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1320.942285] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.033728] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.123268] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.202734] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.271782] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.369492] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.446961] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.532942] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.623236] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.701931] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.798099] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.891507] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1321.951830] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.016957] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.083628] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.156166] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.240825] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.348924] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.496930] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.584957] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.710359] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.830769] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1322.951230] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.069077] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.154547] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.214035] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.270868] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.360938] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.441031] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.489502] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.572234] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.662978] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.745425] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.843411] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1323.940287] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.021784] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.076142] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.150988] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.242595] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.303887] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.379656] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.456885] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.531198] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.615420] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.687057] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.764193] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.848531] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.903756] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.949982] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1324.996880] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.041845] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.079673] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.121586] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.181534] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.258173] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.406853] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.488298] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.595140] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.697723] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.792325] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1325.879883] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.016655] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.151622] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.290649] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.445306] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.533291] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.644958] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.746093] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.833699] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.914734] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1326.991433] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.069410] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.141083] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.211087] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.294777] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.379440] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.473898] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.566891] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.677223] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.759671] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.835600] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.900334] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.933956] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1327.984795] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.033165] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.108810] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.185980] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.279384] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.375255] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.498841] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.658849] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.781336] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1328.916176] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.091041] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.120196] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: disconnect after 21s idle [ 1329.305650] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.468688] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.583718] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.694192] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.789559] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.875449] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1329.942735] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.016959] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.091765] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.205627] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.313787] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.441540] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.545666] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.621048] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.705714] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.794214] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.884790] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1330.990281] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.111529] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.257624] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.351100] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.432847] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.535110] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.629911] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.744447] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.875643] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1331.949801] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1332.023814] rw_seq_cst_vs_d (29818): drop_caches: 3 [ 1342.377335] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 17:36:52 (1776202612) [ 1343.132821] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1343.284615] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1343.501414] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1343.562677] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1343.635737] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1343.789941] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1343.915766] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1344.047818] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1344.388298] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1344.540322] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1344.750771] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1344.860881] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.040357] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.087714] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.135871] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.248375] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.332758] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.433025] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.565919] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.645498] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.794097] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.897554] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1345.974382] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.087652] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.145520] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.200902] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.320573] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.444227] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.556366] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.705451] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.826717] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.877506] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1346.987181] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.046156] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.130077] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.305324] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.410442] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.526379] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.621539] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.712625] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.866983] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1347.986605] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1348.210124] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1348.266182] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1348.475532] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1348.621076] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1348.721023] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1348.896559] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1349.014822] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1349.178205] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1349.291456] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1349.359906] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1349.529513] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1349.748509] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1349.894953] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.084398] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.272983] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.355096] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.413112] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.547832] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.764157] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.821604] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.861946] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1350.948733] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1351.132245] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1351.289828] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1351.379734] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1351.772911] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1352.015339] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1352.082392] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1352.246680] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1352.459413] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1352.572830] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1352.731639] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1352.858849] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1353.047934] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1353.216400] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1353.288668] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1353.419228] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1353.562652] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1353.783323] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1353.932925] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.000167] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.107837] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.179628] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.248895] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.299441] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.373612] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.455686] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.558768] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.707754] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.720718] Lustre: lustre-OST0000-osc-ffff93ebc9842000: disconnect after 23s idle [ 1354.736186] Lustre: Skipped 1 previous similar message [ 1354.823581] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.890048] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1354.954211] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.075418] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.225615] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.307730] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.410642] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.481136] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.579958] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.685907] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1355.822945] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.008418] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.092576] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.159225] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.393103] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.564412] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.703929] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.778858] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.844069] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.913204] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1356.978765] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.048349] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.074381] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.136718] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.224048] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.248397] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.484717] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.586793] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.668417] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.742552] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.921026] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1357.993598] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.036548] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.065904] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.344096] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.427969] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.466538] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.513049] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.550171] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.597490] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.674201] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.749420] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.819283] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1358.995085] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1359.204385] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1359.326676] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1359.510963] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1359.614389] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1359.798862] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1359.845540] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 22s idle [ 1360.012791] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.080280] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.178609] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.308559] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.481783] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.601774] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.727773] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.810405] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1360.869430] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.044677] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.116692] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.212525] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.316303] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.404357] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.477748] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.596415] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.693064] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.872884] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1361.998664] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1362.113489] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1362.181597] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1362.340662] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1362.414126] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1362.627784] rw_seq_cst_vs_d (30403): drop_caches: 3 [ 1371.367581] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 17:37:21 (1776202641) [ 1379.457958] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 17:37:29 (1776202649) [ 1385.439235] Lustre: lustre-OST0001-osc-ffff93ebc9842000: disconnect after 22s idle [ 1389.496348] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 17:37:39 (1776202659) [ 1406.819794] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 17:37:56 (1776202676) [ 1416.811791] Lustre: DEBUG MARKER: loop 5 [ 1421.279458] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: disconnect after 23s idle [ 1423.550627] Lustre: DEBUG MARKER: loop 10 [ 1429.245866] Lustre: DEBUG MARKER: loop 15 [ 1435.137330] Lustre: DEBUG MARKER: loop 20 [ 1443.935750] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 17:38:33 (1776202713) [ 1451.663567] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 17:38:41 (1776202721) [ 1460.485951] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 17:38:49 (1776202729) [ 1467.359877] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: disconnect after 22s idle [ 1467.378250] Lustre: Skipped 1 previous similar message [ 1533.352145] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 17:40:02 (1776202802) [ 1541.134187] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 17:40:11 (1776202811) [ 1548.718879] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 17:40:18 (1776202818) [ 1556.733480] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 17:40:26 (1776202826) [ 1563.890501] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 17:40:33 (1776202833) [ 1571.499259] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 17:40:41 (1776202841) [ 1579.980870] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 1582.130377] Lustre: DEBUG MARKER: SKIP: sanityn test_28 skipping ALWAYS excluded test 28 [ 1584.039664] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 17:40:53 (1776202853) [ 1585.119256] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 21s idle [ 1585.128172] Lustre: Skipped 3 previous similar messages [ 1593.621880] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 17:41:03 (1776202863) [ 1594.465681] Lustre: *** cfs_fail_loc=314, val=0*** [ 1595.551331] Lustre: *** cfs_fail_loc=314, val=0*** [ 1595.556987] Lustre: Skipped 2 previous similar messages [ 1602.562353] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 17:41:12 (1776202872) [ 1612.356279] Lustre: *** cfs_fail_loc=314, val=0*** [ 1612.443533] LustreError: 11-0: lustre-OST0000-osc-ffff93ebc9842000: operation ldlm_enqueue to node 192.168.202.135@tcp failed: rc = -107 [ 1612.459900] Lustre: lustre-OST0000-osc-ffff93ebc9842000: Connection to lustre-OST0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1612.481131] LustreError: lustre-OST0000-osc-ffff93ebc9842000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1612.497579] Lustre: 2275:0:(llite_lib.c:3595:ll_dirty_page_discard_warn()) lustre: dirty page discard: 192.168.202.135@tcp:/lustre/fid: [0x240000403:0x2:0x0]// may get corrupted (rc -108) [ 1612.513585] LustreError: 41222:0:(ldlm_resource.c:1127:ldlm_resource_complain()) lustre-OST0000-osc-ffff93ebc9842000: namespace resource [0x23:0x0:0x0].0x0 (00000000d15af34d) refcount nonzero (1) after lock cleanup; forcing cleanup. [ 1612.527446] Lustre: lustre-OST0000-osc-ffff93ebc9842000: Connection restored to (at 192.168.202.135@tcp) [ 1621.600675] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 17:41:31 (1776202891) [ 1621.900354] LustreError: 41810:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 1624.927380] LustreError: 41810:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1419 awake [ 1631.821971] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 1633.504139] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 17:41:43 (1776202903) [ 1635.346741] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 1637.182542] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-Lock-Cancel ========================================================== 17:41:47 (1776202907) [ 1641.447792] Lustre: lustre-MDT0000-mdc-ffff93ebc3cab000: Connection to lustre-MDT0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1651.698788] LustreError: 166-1: MGC192.168.202.135@tcp: Connection to MGS (at 192.168.202.135@tcp) was lost; in progress operations using this service will fail [ 1651.757036] Lustre: Evicted from MGS (at 192.168.202.135@tcp) after server handle changed from 0xa34a06522aa2858a to 0xa34a06522aac5200 [ 1651.785804] Lustre: MGC192.168.202.135@tcp: Connection restored to (at 192.168.202.135@tcp) [ 1654.108627] Lustre: lustre-MDT0000-mdc-ffff93ebc9842000: Connection restored to (at 192.168.202.135@tcp) [ 1683.916952] Lustre: DEBUG MARKER: == sanityn test 33d: DNE distributed operation should trigger COS ========================================================== 17:42:33 (1776202953) [ 1808.777842] Lustre: DEBUG MARKER: == sanityn test 33e: DNE local operation shouldn't trigger COS ========================================================== 17:44:38 (1776203078) [ 1810.431965] Lustre: DEBUG MARKER: SKIP: sanityn test_33e Need two or more clients, have 1 [ 1812.249339] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 17:44:42 (1776203082) [ 1865.692891] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: Connection to lustre-OST0001 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1865.707451] Lustre: Skipped 1 previous similar message [ 1865.734098] LustreError: lustre-OST0001-osc-ffff93ebc3cab000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1865.750982] LustreError: lustre-OST0001-osc-ffff93ebc9842000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1865.757409] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: Connection restored to (at 192.168.202.135@tcp) [ 1865.790836] Lustre: Skipped 2 previous similar messages [ 1870.793907] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: Connection to lustre-OST0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1870.814453] Lustre: Skipped 1 previous similar message [ 1870.828730] LustreError: lustre-OST0000-osc-ffff93ebc3cab000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1870.850887] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: Connection restored to (at 192.168.202.135@tcp) [ 1887.206594] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: disconnect after 21s idle [ 1887.233869] Lustre: Skipped 1 previous similar message [ 1890.391253] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff93ebc3cab000.ost_server_uuid,osc.lustre-OST0000-osc-ffff93ebc9842000.ost_server_uuid 40 [ 1891.977862] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93ebc3cab000.ost_server_uuid in FULL state after 0 sec [ 1893.362197] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93ebc9842000.ost_server_uuid in FULL state after 0 sec [ 1900.617500] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff93ebc3cab000.ost_server_uuid,osc.lustre-OST0001-osc-ffff93ebc9842000.ost_server_uuid 40 [ 1902.425921] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93ebc3cab000.ost_server_uuid in IDLE state after 0 sec [ 1904.005711] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93ebc9842000.ost_server_uuid in IDLE state after 0 sec [ 1910.981465] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff93ebc3cab000.ost_server_uuid,osc.lustre-OST0000-osc-ffff93ebc9842000.ost_server_uuid 40 [ 1912.627560] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93ebc3cab000.ost_server_uuid in IDLE state after 0 sec [ 1914.265614] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93ebc9842000.ost_server_uuid in FULL state after 0 sec [ 1921.655845] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff93ebc3cab000.ost_server_uuid,osc.lustre-OST0001-osc-ffff93ebc9842000.ost_server_uuid 40 [ 1923.292850] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93ebc3cab000.ost_server_uuid in IDLE state after 0 sec [ 1924.860673] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93ebc9842000.ost_server_uuid in IDLE state after 0 sec [ 1938.585572] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff93ebc3cab000.ost_server_uuid,osc.lustre-OST0000-osc-ffff93ebc9842000.ost_server_uuid 40 [ 1940.123818] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93ebc3cab000.ost_server_uuid in IDLE state after 0 sec [ 1941.970159] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff93ebc9842000.ost_server_uuid in FULL state after 0 sec [ 1947.912792] Lustre: DEBUG MARKER: oleg235-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff93ebc3cab000.ost_server_uuid,osc.lustre-OST0001-osc-ffff93ebc9842000.ost_server_uuid 40 [ 1949.709474] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93ebc3cab000.ost_server_uuid in IDLE state after 0 sec [ 1951.292403] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff93ebc9842000.ost_server_uuid in IDLE state after 0 sec [ 1952.949863] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 17:47:03 (1776203223) [ 1955.386905] Lustre: DEBUG MARKER: Race attempt 0 [ 1958.160414] Lustre: DEBUG MARKER: Wait for 54340 54367 for 60 sec... [ 2027.377972] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 17:48:17 (1776203297) [ 2036.993640] Lustre: DEBUG MARKER: start test - cycle (0) [ 2059.339098] Lustre: DEBUG MARKER: start test - cycle (1) [ 2081.261076] Lustre: DEBUG MARKER: start test - cycle (2) [ 2103.422843] Lustre: DEBUG MARKER: start test - cycle (3) [ 2128.836543] Lustre: DEBUG MARKER: start test - cycle (4) [ 2153.656770] Lustre: DEBUG MARKER: start test - cycle (5) [ 2179.352184] Lustre: DEBUG MARKER: start test - cycle (6) [ 2205.425017] Lustre: DEBUG MARKER: start test - cycle (7) [ 2231.223815] Lustre: DEBUG MARKER: start test - cycle (8) [ 2255.787864] Lustre: DEBUG MARKER: start test - cycle (9) [ 2281.371619] Lustre: DEBUG MARKER: start test - cycle (10) [ 2307.727867] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 17:52:57 (1776203577) [ 2317.280420] Lustre: lustre-OST0001-osc-ffff93ebc9842000: disconnect after 24s idle [ 2317.285856] Lustre: Skipped 2 previous similar messages [ 2396.590833] Lustre: DEBUG MARKER: == sanityn test 39a: test from 11063 ============================================================================================ 17:54:26 (1776203666) [ 2406.723685] Lustre: DEBUG MARKER: == sanityn test 39b: 11063 problem 1 ============================================================================================ 17:54:36 (1776203676) [ 2416.954540] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 17:54:46 (1776203686) [ 2424.570533] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 17:54:55 (1776203695) [ 2425.192669] Lustre: *** cfs_fail_loc=411, val=0*** [ 2432.867580] Lustre: DEBUG MARKER: == sanityn test 40a: pdirops: create vs others ======================================================================== 17:55:03 (1776203703) [ 2449.935799] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 17:55:19 (1776203719) [ 2466.776297] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 17:55:37 (1776203737) [ 2483.899823] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 17:55:53 (1776203753) [ 2502.708738] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 17:56:12 (1776203772) [ 2519.489653] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 17:56:29 (1776203789) [ 2533.591372] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 17:56:43 (1776203803) [ 2548.526416] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 17:56:58 (1776203818) [ 2562.370285] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 17:57:12 (1776203832) [ 2575.748672] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 17:57:25 (1776203845) [ 2578.404914] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 21s idle [ 2578.417119] Lustre: Skipped 8 previous similar messages [ 2589.317933] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 17:57:39 (1776203859) [ 2602.125989] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 17:57:52 (1776203872) [ 2615.912234] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 17:58:05 (1776203885) [ 2630.199681] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 17:58:20 (1776203900) [ 3746.531960] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 18:16:56 (1776205016) [ 3759.085916] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 18:17:09 (1776205029) [ 3771.439819] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 18:17:21 (1776205041) [ 3783.453392] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 18:17:33 (1776205053) [ 3795.086985] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 18:17:45 (1776205065) [ 3805.154012] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 22s idle [ 3805.160174] Lustre: Skipped 5 previous similar messages [ 3805.943769] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 18:17:56 (1776205076) [ 3818.179946] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 18:18:08 (1776205088) [ 3831.084553] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 18:18:21 (1776205101) [ 3844.101552] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 18:18:34 (1776205114) [ 3919.127396] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 18:19:49 (1776205189) [ 3933.717105] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 18:20:03 (1776205203) [ 3948.653501] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 18:20:18 (1776205218) [ 3962.246814] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 18:20:32 (1776205232) [ 3963.875533] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 21s idle [ 3963.879443] Lustre: Skipped 1 previous similar message [ 3976.598810] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 18:20:46 (1776205246) [ 3990.955881] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 18:21:01 (1776205261) [ 4004.848637] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 18:21:14 (1776205274) [ 4019.005668] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 18:21:29 (1776205289) [ 4032.873315] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 18:21:43 (1776205303) [ 4187.673842] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 18:24:18 (1776205458) [ 4347.871994] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 24s idle [ 4347.883990] Lustre: Skipped 4 previous similar messages [ 4658.143400] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: disconnect after 20s idle [ 4658.161977] Lustre: Skipped 4 previous similar messages [ 5508.716685] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 18:46:18 (1776206778) [ 5522.595514] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 18:46:32 (1776206792) [ 5523.425277] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 20s idle [ 5523.428268] Lustre: Skipped 2 previous similar messages [ 5537.385472] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 18:46:47 (1776206807) [ 5552.968851] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 18:47:02 (1776206822) [ 5567.856772] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 18:47:17 (1776206837) [ 5582.699855] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 18:47:32 (1776206852) [ 5597.651743] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 18:47:47 (1776206867) [ 5612.093708] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 18:48:01 (1776206881) [ 5626.111174] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 18:48:16 (1776206896) [ 5643.198845] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 18:48:31 (1776206911) [ 5790.710881] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 18:51:00 (1776207060) [ 5806.938987] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 18:51:16 (1776207076) [ 5824.626888] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 18:51:33 (1776207093) [ 5841.007497] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 18:51:50 (1776207110) [ 5855.511670] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 18:52:05 (1776207125) [ 5870.755917] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 18:52:20 (1776207140) [ 5887.195064] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 18:52:36 (1776207156) [ 5903.041718] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 18:52:53 (1776207173) [ 5918.104701] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 18:53:07 (1776207187) [ 6224.865697] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 24s idle [ 6224.874357] Lustre: Skipped 10 previous similar messages [ 6854.638624] Lustre: lustre-OST0000-osc-ffff93ebc3cab000: disconnect after 25s idle [ 6854.660421] Lustre: Skipped 10 previous similar messages [ 7323.678433] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 19:16:33 (1776208593) [ 7339.549923] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 19:16:49 (1776208609) [ 7355.855534] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 19:17:05 (1776208625) [ 7368.973297] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 19:17:18 (1776208638) [ 7384.042540] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 19:17:34 (1776208654) [ 7398.777562] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 19:17:48 (1776208668) [ 7416.101363] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 19:18:06 (1776208686) [ 7430.724600] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 19:18:20 (1776208700) [ 7446.356034] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 19:18:36 (1776208716) [ 7462.113629] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 19:18:51 (1776208731) [ 7469.028271] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: disconnect after 24s idle [ 7469.033262] Lustre: Skipped 11 previous similar messages [ 7478.861712] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 19:19:08 (1776208748) [ 7494.526247] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 19:19:24 (1776208764) [ 7508.577322] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 19:19:38 (1776208778) [ 7522.132143] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 19:19:52 (1776208792) [ 7537.398306] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 19:20:07 (1776208807) [ 7551.529638] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 19:20:21 (1776208821) [ 7570.640861] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 19:20:40 (1776208840) [ 7571.141273] LustreError: 5584:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 410 sleeping for 2000ms [ 7573.239181] LustreError: 5584:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 410 awake [ 7582.529456] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 19:20:52 (1776208852) [ 7591.880452] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 19:21:02 (1776208862) [ 7592.501534] LustreError: 267566:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 7596.593666] LustreError: 267566:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 7596.627662] LustreError: 267566:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 7600.695154] LustreError: 267566:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 7600.759968] LustreError: 267572:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 7604.823196] LustreError: 267572:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 7612.199866] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 19:21:22 (1776208882) [ 7626.377107] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 19:21:36 (1776208896) [ 7634.939543] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 19:21:44 (1776208904) [ 7645.572654] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 19:21:55 (1776208915) [ 7680.466232] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 19:22:30 (1776208950) [ 7695.448360] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 19:22:45 (1776208965) [ 7710.526520] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 19:22:59 (1776208979) [ 7730.757373] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 19:23:20 (1776209000) [ 7748.564097] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 19:23:38 (1776209018) [ 7758.700180] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 7768.629413] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 19:23:58 (1776209038) [ 7778.115503] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 19:24:07 (1776209047) [ 7787.557179] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 19:24:17 (1776209057) [ 7795.431164] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 19:24:25 (1776209065) [ 7838.955577] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 19:25:08 (1776209108) [ 7898.860351] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 19:26:08 (1776209168) [ 7906.757339] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 19:26:16 (1776209176) [ 7913.965792] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 19:26:23 (1776209183) [ 7917.445074] LustreError: 11-0: lustre-MDT0000-mdc-ffff93ebc3cab000: operation ldlm_enqueue to node 192.168.202.135@tcp failed: rc = -35 [ 7917.455801] LustreError: Skipped 1 previous similar message [ 7925.746813] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 19:26:35 (1776209195) [ 7926.878526] LustreError: 2274:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 31d sleeping for 2000ms [ 7928.959185] LustreError: 2274:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 31d awake [ 7938.541864] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 19:26:48 (1776209208) [ 8118.339619] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 19:29:47 (1776209387) [ 8131.659740] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 19:30:01 (1776209401) [ 8134.640319] Lustre: lustre-OST0000-osc-ffff93ebc9842000: disconnect after 24s idle [ 8134.647366] Lustre: Skipped 6 previous similar messages [ 8147.031711] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 19:30:17 (1776209417) [ 8167.996097] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 19:30:37 (1776209437) [ 8186.431482] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 19:30:56 (1776209456) [ 8215.451416] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 19:31:25 (1776209485) [ 8242.409286] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 19:31:52 (1776209512) [ 8254.398305] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 19:32:04 (1776209524) [ 8267.650558] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 19:32:17 (1776209537) [ 8292.458257] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 19:32:42 (1776209562) [ 8348.845578] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 19:33:38 (1776209618) [ 8488.127522] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with NID/JobID/OPCode expression ========================================================== 19:35:57 (1776209757) [ 8743.903940] Lustre: lustre-OST0001-osc-ffff93ebc3cab000: disconnect after 23s idle [ 8743.908263] Lustre: Skipped 14 previous similar messages [ 8848.613118] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 19:41:57 (1776210117) [ 8861.249235] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 19:42:10 (1776210130) [ 8919.856491] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 19:43:09 (1776210189) [ 8998.115303] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 19:44:28 (1776210268) [ 9013.783850] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 19:44:43 (1776210283) [ 9160.238442] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 19:47:09 (1776210429) [ 9203.256135] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 19:47:52 (1776210472) [ 9215.792873] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 19:48:05 (1776210485) [ 9235.693347] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 19:48:25 (1776210505) [ 9238.471203] LustreError: 307282:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff93ebc3cab000: inode [0x200000402:0x7c5:0x0] mdc close failed: rc = -116 [ 9239.038983] LustreError: 307283:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff93ebc3cab000: inode [0x240000402:0x5f6:0x0] mdc close failed: rc = -116 [ 9239.047317] LustreError: 307283:0:(file.c:246:ll_close_inode_openhandle()) Skipped 1 previous similar message [ 9248.883448] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 19:48:38 (1776210518) [ 9277.601863] LustreError: 308165:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff93ebc9842000: inode [0x200000402:0x812:0x0] mdc close failed: rc = -2 [ 9277.625611] LustreError: 308165:0:(file.c:246:ll_close_inode_openhandle()) Skipped 9 previous similar messages [ 9283.405721] LustreError: 308226:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff93ebc9842000: inode [0x240000402:0x685:0x0] mdc close failed: rc = -2 [ 9289.468217] LustreError: 308279:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff93ebc3cab000: inode [0x200000403:0x1e1a:0x0] mdc close failed: rc = -116 [ 9302.618485] Lustre: dir [0x200000402:0x87b:0x0] stripe 1 readdir failed: -2, directory is partially accessed! [ 9305.854839] LustreError: 308468:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff93ebc3cab000: inode [0x200000402:0x880:0x0] mdc close failed: rc = -116 [ 9305.865719] LustreError: 308468:0:(file.c:246:ll_close_inode_openhandle()) Skipped 1 previous similar message [ 9316.608724] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 19:49:46 (1776210586) [ 9324.864143] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 19:49:54 (1776210594) [ 9434.367488] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 19:51:44 (1776210704) [ 9435.935693] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 9437.796599] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 19:51:47 (1776210707) [ 9445.115894] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 19:51:55 (1776210715) [ 9573.554384] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 19:54:03 (1776210843) [ 9586.467876] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 19:54:16 (1776210856) [ 9775.158610] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 19:57:24 (1776211044) [ 9963.334205] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 20:00:33 (1776211233) [ 9970.685896] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 20:00:40 (1776211240) [ 9988.176261] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 20:00:58 (1776211258) [ 9988.818480] Lustre: DEBUG MARKER: write [ 9988.880906] LustreError: 20990:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 sleeping for 5000ms [ 9990.929949] Lustre: DEBUG MARKER: kill 320637 [ 9990.942941] LustreError: 320637:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 329 sleeping for 6000ms [ 9993.919177] LustreError: 20990:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 awake [ 9997.001562] LustreError: 320637:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 329 awake [10004.282773] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 20:01:14 (1776211274) [10005.353202] LustreError: 321248:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1424 sleeping for 5000ms [10007.345534] LustreError: 321248:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [10017.284590] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 20:01:27 (1776211287) [10019.144187] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [10020.927825] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 20:01:30 (1776211290) [10028.018638] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 20:01:37 (1776211297) [10036.602236] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 20:01:46 (1776211306) [10043.763176] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 20:01:53 (1776211313) [10052.446622] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 20:02:01 (1776211321) [10060.824722] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 20:02:11 (1776211331) [10069.484554] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 20:02:19 (1776211339) [10078.395287] Lustre: DEBUG MARKER: == sanityn test 102: Test open by handle of unlinked file ========================================================== 20:02:28 (1776211348) [10088.107314] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 20:02:37 (1776211357) [10090.827061] Lustre: *** cfs_fail_loc=415, val=0*** [10107.139937] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 20:02:56 (1776211376) [10139.564302] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 20:03:29 (1776211409) [10139.866466] LustreError: 5592:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [10144.871184] LustreError: 5592:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [10149.983124] LustreError: 5592:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [10149.988843] LustreError: 5592:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [10150.002140] LustreError: 5592:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 1 previous similar message [10160.039384] LustreError: 5592:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [10160.057615] LustreError: 5592:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [10170.200842] LustreError: 287736:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [10170.214280] LustreError: 287736:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [10180.257519] LustreError: 287736:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [10180.262927] LustreError: 287736:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [10205.402963] LustreError: 5592:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [10205.420217] LustreError: 5592:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [10215.447186] LustreError: 5591:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [10215.472071] LustreError: 5591:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [10231.202655] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 20:05:00 (1776211500) [10242.108471] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 20:05:11 (1776211511) [10253.889375] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 20:05:22 (1776211522) [10262.913674] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 20:05:32 (1776211532) [10274.155748] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 20:05:43 (1776211543) [10288.102923] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 20:05:58 (1776211558) [10288.692630] LustreError: 331891:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 414 sleeping for 4000ms [10288.699265] LustreError: 331891:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 2 previous similar messages [10292.777533] LustreError: 331891:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 414 awake [10292.797515] LustreError: 331891:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [10301.423138] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 20:06:10 (1776211570) [10307.177812] Lustre: Unmounted lustre-client [10311.302246] Lustre: Unmounted lustre-client [10312.795392] Lustre: DEBUG MARKER: Iteration 1 [10314.035897] LustreError: 332774:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10314.040411] LustreError: 332772:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10314.050249] LustreError: 332774:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10314.374480] Lustre: Mounted lustre-client [10316.522581] Lustre: Unmounted lustre-client [10319.907065] Key type lgssc unregistered [10320.197188] LNet: 333127:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10321.250396] LNet: Removed LNI 192.168.202.35@tcp [10321.975178] Key type .llcrypt unregistered [10321.979269] Key type ._llcrypt unregistered [10322.941055] alg: No test for adler32 (adler32-zlib) [10323.711592] Key type ._llcrypt registered [10323.722751] Key type .llcrypt registered [10324.299618] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10324.928445] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10325.766833] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10325.773925] LNet: Accept secure, port 988 [10327.543126] Key type lgssc registered [10329.172678] Lustre: Echo OBD driver; http://www.lustre.org/ [10342.888577] Lustre: DEBUG MARKER: Iteration 2 [10343.453220] LustreError: 333919:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10343.453890] LustreError: 333925:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10343.474812] LustreError: 333919:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [10344.475796] Lustre: Mounted lustre-client [10346.265376] Lustre: Unmounted lustre-client [10348.900653] Key type lgssc unregistered [10349.133214] LNet: 334272:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10350.185616] LNet: Removed LNI 192.168.202.35@tcp [10350.902675] Key type .llcrypt unregistered [10350.909116] Key type ._llcrypt unregistered [10352.560186] alg: No test for adler32 (adler32-zlib) [10353.317142] Key type ._llcrypt registered [10353.323961] Key type .llcrypt registered [10353.674814] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10354.059640] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10354.372403] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10354.386564] LNet: Accept secure, port 988 [10356.031158] Key type lgssc registered [10357.397614] Lustre: Echo OBD driver; http://www.lustre.org/ [10368.180841] Lustre: DEBUG MARKER: Iteration 3 [10368.580957] LustreError: 335066:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10368.582181] LustreError: 335067:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10368.609977] LustreError: 335066:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [10369.583794] Lustre: Mounted lustre-client [10370.969032] Lustre: Unmounted lustre-client [10373.884865] Key type lgssc unregistered [10374.192204] LNet: 335415:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10375.269566] LNet: Removed LNI 192.168.202.35@tcp [10375.929697] Key type .llcrypt unregistered [10375.932480] Key type ._llcrypt unregistered [10376.978589] alg: No test for adler32 (adler32-zlib) [10377.750537] Key type ._llcrypt registered [10377.752158] Key type .llcrypt registered [10378.061951] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10378.553263] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10378.867786] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10378.882652] LNet: Accept secure, port 988 [10380.530416] Key type lgssc registered [10382.008276] Lustre: Echo OBD driver; http://www.lustre.org/ [10396.463797] Lustre: DEBUG MARKER: Iteration 4 [10396.980224] LustreError: 336225:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10396.981587] LustreError: 336226:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10397.006617] LustreError: 336225:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [10398.085533] Lustre: Mounted lustre-client [10399.683023] Lustre: Unmounted lustre-client [10402.771821] Key type lgssc unregistered [10403.052721] LNet: 336575:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10404.129169] LNet: Removed LNI 192.168.202.35@tcp [10405.313925] Key type .llcrypt unregistered [10405.319483] Key type ._llcrypt unregistered [10407.257788] alg: No test for adler32 (adler32-zlib) [10408.016153] Key type ._llcrypt registered [10408.025165] Key type .llcrypt registered [10408.378785] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10408.871297] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10409.157093] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10409.161877] LNet: Accept secure, port 988 [10410.935126] Key type lgssc registered [10412.819147] Lustre: Echo OBD driver; http://www.lustre.org/ [10427.333975] Lustre: DEBUG MARKER: Iteration 5 [10427.951516] LustreError: 337372:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10427.952200] LustreError: 337373:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10427.968670] LustreError: 337372:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [10429.050788] Lustre: Mounted lustre-client [10431.157857] Lustre: Unmounted lustre-client [10434.725835] Key type lgssc unregistered [10435.011897] LNet: 337725:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10436.064589] LNet: Removed LNI 192.168.202.35@tcp [10437.167283] Key type .llcrypt unregistered [10437.173192] Key type ._llcrypt unregistered [10438.118360] alg: No test for adler32 (adler32-zlib) [10438.938779] Key type ._llcrypt registered [10438.941317] Key type .llcrypt registered [10439.187799] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10439.681953] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10439.977383] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10439.987608] LNet: Accept secure, port 988 [10441.767580] Key type lgssc registered [10443.500379] Lustre: Echo OBD driver; http://www.lustre.org/ [10458.426598] Lustre: DEBUG MARKER: Iteration 6 [10458.760663] LustreError: 338520:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10458.777271] LustreError: 338526:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10458.787481] LustreError: 338520:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4973 [10459.956282] Lustre: Mounted lustre-client [10462.661893] Lustre: Unmounted lustre-client [10468.531933] Key type lgssc unregistered [10469.007752] LNet: 338872:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10470.059063] LNet: Removed LNI 192.168.202.35@tcp [10470.801612] Key type .llcrypt unregistered [10470.803090] Key type ._llcrypt unregistered [10472.328184] alg: No test for adler32 (adler32-zlib) [10473.113839] Key type ._llcrypt registered [10473.115857] Key type .llcrypt registered [10473.581855] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10474.187081] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10474.686672] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10474.690598] LNet: Accept secure, port 988 [10476.515525] Key type lgssc registered [10478.416176] Lustre: Echo OBD driver; http://www.lustre.org/ [10494.682068] Lustre: DEBUG MARKER: Iteration 7 [10495.296495] LustreError: 339667:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10495.296596] LustreError: 339669:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10495.321773] LustreError: 339667:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [10496.496821] Lustre: Mounted lustre-client [10499.063978] Lustre: Unmounted lustre-client [10502.008479] Key type lgssc unregistered [10502.308059] LNet: 340019:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10503.340648] LNet: Removed LNI 192.168.202.35@tcp [10504.048103] Key type .llcrypt unregistered [10504.051205] Key type ._llcrypt unregistered [10505.244149] alg: No test for adler32 (adler32-zlib) [10506.028778] Key type ._llcrypt registered [10506.033542] Key type .llcrypt registered [10506.367774] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10506.733682] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10506.956119] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10506.959514] LNet: Accept secure, port 988 [10508.759123] Key type lgssc registered [10510.351471] Lustre: Echo OBD driver; http://www.lustre.org/ [10524.975289] Lustre: DEBUG MARKER: Iteration 8 [10525.497118] LustreError: 340816:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10525.505801] LustreError: 340817:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10525.515982] LustreError: 340816:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10526.661952] Lustre: Mounted lustre-client [10526.673502] Lustre: Skipped 1 previous similar message [10528.757978] Lustre: Unmounted lustre-client [10532.165322] Key type lgssc unregistered [10532.417290] LNet: 341166:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10533.472479] LNet: Removed LNI 192.168.202.35@tcp [10534.290671] Key type .llcrypt unregistered [10534.293880] Key type ._llcrypt unregistered [10534.985411] alg: No test for adler32 (adler32-zlib) [10535.736474] Key type ._llcrypt registered [10535.742567] Key type .llcrypt registered [10536.065670] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10536.432761] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10536.680418] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10536.686983] LNet: Accept secure, port 988 [10538.399150] Key type lgssc registered [10540.170326] Lustre: Echo OBD driver; http://www.lustre.org/ [10554.470830] Lustre: DEBUG MARKER: Iteration 9 [10554.918591] LustreError: 341963:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10554.924618] LustreError: 341962:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10554.934782] LustreError: 341963:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [10555.978857] Lustre: Mounted lustre-client [10555.990192] Lustre: Skipped 1 previous similar message [10557.936559] Lustre: Unmounted lustre-client [10561.592994] Key type lgssc unregistered [10561.824172] LNet: 342313:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10562.852611] LNet: Removed LNI 192.168.202.35@tcp [10563.810263] Key type .llcrypt unregistered [10563.820940] Key type ._llcrypt unregistered [10564.850454] alg: No test for adler32 (adler32-zlib) [10565.613507] Key type ._llcrypt registered [10565.615868] Key type .llcrypt registered [10565.845265] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10566.092376] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10566.329413] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10566.334908] LNet: Accept secure, port 988 [10568.023230] Key type lgssc registered [10569.779728] Lustre: Echo OBD driver; http://www.lustre.org/ [10585.792903] Lustre: DEBUG MARKER: Iteration 10 [10586.517783] LustreError: 343108:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10586.519467] LustreError: 343110:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10586.549781] LustreError: 343108:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4978 [10587.757145] Lustre: Mounted lustre-client [10589.372972] Lustre: Unmounted lustre-client [10592.938841] Key type lgssc unregistered [10593.318113] LNet: 343458:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10594.400959] LNet: Removed LNI 192.168.202.35@tcp [10595.292175] Key type .llcrypt unregistered [10595.294656] Key type ._llcrypt unregistered [10596.472376] alg: No test for adler32 (adler32-zlib) [10597.232395] Key type ._llcrypt registered [10597.235401] Key type .llcrypt registered [10597.503583] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10597.846489] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10598.072446] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10598.085472] LNet: Accept secure, port 988 [10599.791191] Key type lgssc registered [10601.332269] Lustre: Echo OBD driver; http://www.lustre.org/ [10617.453343] Lustre: DEBUG MARKER: Iteration 11 [10617.904694] LustreError: 344254:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10617.908958] LustreError: 344255:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10617.917878] LustreError: 344254:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [10618.941380] Lustre: Mounted lustre-client [10620.448573] Lustre: Unmounted lustre-client [10623.704190] Key type lgssc unregistered [10624.019658] LNet: 344604:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10625.065859] LNet: Removed LNI 192.168.202.35@tcp [10625.984757] Key type .llcrypt unregistered [10625.987730] Key type ._llcrypt unregistered [10627.166400] alg: No test for adler32 (adler32-zlib) [10627.935076] Key type ._llcrypt registered [10627.942332] Key type .llcrypt registered [10628.281809] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10628.804326] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10629.037393] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10629.040277] LNet: Accept secure, port 988 [10630.735132] Key type lgssc registered [10632.011630] Lustre: Echo OBD driver; http://www.lustre.org/ [10645.590670] Lustre: DEBUG MARKER: Iteration 12 [10646.073475] LustreError: 345401:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10646.247806] LustreError: 345400:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10646.264539] LustreError: 345401:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4813 [10647.306505] Lustre: Mounted lustre-client [10647.317175] Lustre: Skipped 1 previous similar message [10649.110802] Lustre: Unmounted lustre-client [10651.776598] Key type lgssc unregistered [10651.982363] LNet: 345751:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10652.006924] LNet: Removed LNI 192.168.202.35@tcp [10652.915451] Key type .llcrypt unregistered [10652.924698] Key type ._llcrypt unregistered [10654.124158] alg: No test for adler32 (adler32-zlib) [10654.993561] Key type ._llcrypt registered [10654.995524] Key type .llcrypt registered [10655.241593] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10655.701787] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10656.060297] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10656.064771] LNet: Accept secure, port 988 [10657.807204] Key type lgssc registered [10659.385127] Lustre: Echo OBD driver; http://www.lustre.org/ [10673.543759] Lustre: DEBUG MARKER: Iteration 13 [10674.228763] LustreError: 346546:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10674.232828] LustreError: 346547:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10674.244043] LustreError: 346546:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [10675.334072] Lustre: Mounted lustre-client [10677.093979] Lustre: Unmounted lustre-client [10680.422210] Key type lgssc unregistered [10680.678584] LNet: 346896:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10681.704936] LNet: Removed LNI 192.168.202.35@tcp [10682.496716] Key type .llcrypt unregistered [10682.498884] Key type ._llcrypt unregistered [10684.050824] alg: No test for adler32 (adler32-zlib) [10684.810589] Key type ._llcrypt registered [10684.812277] Key type .llcrypt registered [10685.200687] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10685.617146] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10685.877812] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10685.886876] LNet: Accept secure, port 988 [10687.624376] Key type lgssc registered [10688.792623] Lustre: Echo OBD driver; http://www.lustre.org/ [10703.063668] Lustre: DEBUG MARKER: Iteration 14 [10703.417298] LustreError: 347692:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10703.417373] LustreError: 347694:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10703.432750] LustreError: 347692:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [10704.496675] Lustre: Mounted lustre-client [10706.023579] Lustre: Unmounted lustre-client [10708.881841] Key type lgssc unregistered [10709.089220] LNet: 348048:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10710.117693] LNet: Removed LNI 192.168.202.35@tcp [10710.846941] Key type .llcrypt unregistered [10710.850492] Key type ._llcrypt unregistered [10712.159709] alg: No test for adler32 (adler32-zlib) [10712.923944] Key type ._llcrypt registered [10712.935348] Key type .llcrypt registered [10713.191064] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10713.433495] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10713.668138] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10713.670532] LNet: Accept secure, port 988 [10715.360989] Key type lgssc registered [10716.619316] Lustre: Echo OBD driver; http://www.lustre.org/ [10728.619805] Lustre: DEBUG MARKER: Iteration 15 [10729.234609] LustreError: 348844:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10729.237082] LustreError: 348845:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10729.242054] LustreError: 348844:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=5000 [10730.258356] Lustre: Mounted lustre-client [10730.265855] Lustre: Skipped 1 previous similar message [10731.357123] Lustre: Unmounted lustre-client [10734.112352] Key type lgssc unregistered [10734.418191] LNet: 349195:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10735.458149] LNet: Removed LNI 192.168.202.35@tcp [10736.321927] Key type .llcrypt unregistered [10736.324458] Key type ._llcrypt unregistered [10737.450598] alg: No test for adler32 (adler32-zlib) [10738.253422] Key type ._llcrypt registered [10738.261046] Key type .llcrypt registered [10738.619939] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10739.074348] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10739.442474] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10739.453069] LNet: Accept secure, port 988 [10741.232301] Key type lgssc registered [10743.145990] Lustre: Echo OBD driver; http://www.lustre.org/ [10756.494805] Lustre: DEBUG MARKER: Iteration 16 [10757.027273] LustreError: 349992:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10757.030736] LustreError: 349993:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10757.047564] LustreError: 349992:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [10758.132915] Lustre: Mounted lustre-client [10758.143158] Lustre: Skipped 1 previous similar message [10760.176713] Lustre: Unmounted lustre-client [10763.132253] Key type lgssc unregistered [10763.544279] LNet: 350344:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10764.576918] LNet: Removed LNI 192.168.202.35@tcp [10765.288628] Key type .llcrypt unregistered [10765.292344] Key type ._llcrypt unregistered [10766.502974] alg: No test for adler32 (adler32-zlib) [10767.300467] Key type ._llcrypt registered [10767.302647] Key type .llcrypt registered [10767.562358] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10767.942832] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10768.147724] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10768.152947] LNet: Accept secure, port 988 [10769.839147] Key type lgssc registered [10771.217568] Lustre: Echo OBD driver; http://www.lustre.org/ [10783.321751] Lustre: DEBUG MARKER: Iteration 17 [10783.808965] LustreError: 351142:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10783.810106] LustreError: 351141:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10783.827305] LustreError: 351142:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4983 [10784.906747] Lustre: Mounted lustre-client [10784.925513] Lustre: Skipped 1 previous similar message [10786.366333] Lustre: Unmounted lustre-client [10788.829762] Key type lgssc unregistered [10789.055005] LNet: 351492:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10790.116262] LNet: Removed LNI 192.168.202.35@tcp [10790.847624] Key type .llcrypt unregistered [10790.850286] Key type ._llcrypt unregistered [10792.391717] alg: No test for adler32 (adler32-zlib) [10793.148775] Key type ._llcrypt registered [10793.151637] Key type .llcrypt registered [10793.521555] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10794.088217] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10794.540389] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10794.551155] LNet: Accept secure, port 988 [10796.319816] Key type lgssc registered [10798.445228] Lustre: Echo OBD driver; http://www.lustre.org/ [10813.993397] Lustre: DEBUG MARKER: Iteration 18 [10814.415216] LustreError: 352291:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10814.415253] LustreError: 352292:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10814.431823] LustreError: 352291:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10815.476719] Lustre: Mounted lustre-client [10815.483889] Lustre: Skipped 1 previous similar message [10817.329179] Lustre: Unmounted lustre-client [10820.298948] Key type lgssc unregistered [10820.598710] LNet: 352643:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10821.674655] LNet: Removed LNI 192.168.202.35@tcp [10822.696753] Key type .llcrypt unregistered [10822.703805] Key type ._llcrypt unregistered [10824.195764] alg: No test for adler32 (adler32-zlib) [10824.953948] Key type ._llcrypt registered [10824.960561] Key type .llcrypt registered [10825.351421] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10825.780980] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10826.061603] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10826.072026] LNet: Accept secure, port 988 [10827.815131] Key type lgssc registered [10829.102637] Lustre: Echo OBD driver; http://www.lustre.org/ [10843.004742] Lustre: DEBUG MARKER: Iteration 19 [10843.415549] LustreError: 353440:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10843.415837] LustreError: 353439:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10843.439257] LustreError: 353440:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4983 [10844.546058] Lustre: Mounted lustre-client [10844.560125] Lustre: Skipped 1 previous similar message [10846.476887] Lustre: Unmounted lustre-client [10849.998293] Key type lgssc unregistered [10850.192365] LNet: 353789:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10851.234406] LNet: Removed LNI 192.168.202.35@tcp [10851.994099] Key type .llcrypt unregistered [10851.996397] Key type ._llcrypt unregistered [10852.723419] alg: No test for adler32 (adler32-zlib) [10853.535429] Key type ._llcrypt registered [10853.543898] Key type .llcrypt registered [10853.839933] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10854.258862] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10854.462036] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10854.512527] LNet: Accept secure, port 988 [10856.263588] Key type lgssc registered [10857.589259] Lustre: Echo OBD driver; http://www.lustre.org/ [10872.625569] Lustre: DEBUG MARKER: Iteration 20 [10873.253641] LustreError: 354586:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10873.256137] LustreError: 354587:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10873.271259] LustreError: 354586:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10874.322909] Lustre: Mounted lustre-client [10875.921068] Lustre: Unmounted lustre-client [10878.585980] Key type lgssc unregistered [10878.922774] LNet: 354937:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10879.969457] LNet: Removed LNI 192.168.202.35@tcp [10881.152030] Key type .llcrypt unregistered [10881.163832] Key type ._llcrypt unregistered [10882.745522] alg: No test for adler32 (adler32-zlib) [10883.511442] Key type ._llcrypt registered [10883.516460] Key type .llcrypt registered [10883.799913] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10884.081893] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10884.370889] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10884.377738] LNet: Accept secure, port 988 [10886.095799] Key type lgssc registered [10887.312656] Lustre: Echo OBD driver; http://www.lustre.org/ [10901.243637] Lustre: DEBUG MARKER: Iteration 21 [10901.512445] LustreError: 355731:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10901.512457] LustreError: 355733:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10901.530566] LustreError: 355731:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [10902.570859] Lustre: Mounted lustre-client [10902.578419] Lustre: Skipped 1 previous similar message [10904.022602] Lustre: Unmounted lustre-client [10906.772497] Key type lgssc unregistered [10907.036761] LNet: 356085:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10907.051170] LNet: Removed LNI 192.168.202.35@tcp [10907.649468] Key type .llcrypt unregistered [10907.653595] Key type ._llcrypt unregistered [10908.516961] alg: No test for adler32 (adler32-zlib) [10909.293175] Key type ._llcrypt registered [10909.297133] Key type .llcrypt registered [10909.556849] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10909.974659] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10910.161911] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10910.165087] LNet: Accept secure, port 988 [10911.810761] Key type lgssc registered [10912.885598] Lustre: Echo OBD driver; http://www.lustre.org/ [10923.507587] Lustre: DEBUG MARKER: Iteration 22 [10923.921682] LustreError: 356875:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10923.923760] LustreError: 356879:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10923.971386] LustreError: 356875:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4977 [10925.097409] Lustre: Mounted lustre-client [10926.785745] Lustre: Unmounted lustre-client [10929.904272] Key type lgssc unregistered [10930.198949] LNet: 357233:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10931.235630] LNet: Removed LNI 192.168.202.35@tcp [10932.133657] Key type .llcrypt unregistered [10932.135201] Key type ._llcrypt unregistered [10933.245843] alg: No test for adler32 (adler32-zlib) [10934.003656] Key type ._llcrypt registered [10934.011626] Key type .llcrypt registered [10934.268477] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10934.598724] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10934.906745] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10934.916945] LNet: Accept secure, port 988 [10936.631154] Key type lgssc registered [10938.064616] Lustre: Echo OBD driver; http://www.lustre.org/ [10950.727689] Lustre: DEBUG MARKER: Iteration 23 [10951.246584] LustreError: 358030:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10951.250176] LustreError: 358031:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10951.286077] LustreError: 358030:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4966 [10952.368285] Lustre: Mounted lustre-client [10953.827124] Lustre: Unmounted lustre-client [10956.571293] Key type lgssc unregistered [10956.896758] LNet: 358380:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10957.921511] LNet: Removed LNI 192.168.202.35@tcp [10958.811919] Key type .llcrypt unregistered [10958.814875] Key type ._llcrypt unregistered [10959.819076] alg: No test for adler32 (adler32-zlib) [10960.653571] Key type ._llcrypt registered [10960.657803] Key type .llcrypt registered [10960.980851] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10961.399416] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10961.677495] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10961.685459] LNet: Accept secure, port 988 [10963.351191] Key type lgssc registered [10965.206489] Lustre: Echo OBD driver; http://www.lustre.org/ [10980.841315] Lustre: DEBUG MARKER: Iteration 24 [10981.556456] LustreError: 359176:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10981.557842] LustreError: 359175:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10981.589645] LustreError: 359176:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4982 [10982.688885] Lustre: Mounted lustre-client [10982.690377] Lustre: Skipped 1 previous similar message [10984.720923] Lustre: Unmounted lustre-client [10988.383565] Key type lgssc unregistered [10988.744179] LNet: 359528:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10989.794397] LNet: Removed LNI 192.168.202.35@tcp [10991.100509] Key type .llcrypt unregistered [10991.102795] Key type ._llcrypt unregistered [10992.517051] alg: No test for adler32 (adler32-zlib) [10993.278808] Key type ._llcrypt registered [10993.282962] Key type .llcrypt registered [10993.589964] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10993.864353] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [10994.126266] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [10994.129920] LNet: Accept secure, port 988 [10995.880539] Key type lgssc registered [10997.378184] Lustre: Echo OBD driver; http://www.lustre.org/ [11010.907347] Lustre: DEBUG MARKER: Iteration 25 [11011.459542] LustreError: 360326:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11011.459846] LustreError: 360325:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11011.480651] LustreError: 360326:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4993 [11012.577051] Lustre: Mounted lustre-client [11014.024671] Lustre: Unmounted lustre-client [11016.707060] Key type lgssc unregistered [11017.092452] LNet: 360677:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11018.159284] LNet: Removed LNI 192.168.202.35@tcp [11018.957300] Key type .llcrypt unregistered [11018.960671] Key type ._llcrypt unregistered [11020.022586] alg: No test for adler32 (adler32-zlib) [11020.783519] Key type ._llcrypt registered [11020.786617] Key type .llcrypt registered [11021.108602] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11021.449295] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11021.643552] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11021.646666] LNet: Accept secure, port 988 [11023.335207] Key type lgssc registered [11024.844336] Lustre: Echo OBD driver; http://www.lustre.org/ [11036.654989] Lustre: DEBUG MARKER: Iteration 26 [11037.062337] LustreError: 361473:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11037.066636] LustreError: 361472:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11037.072414] LustreError: 361473:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [11038.082779] Lustre: Mounted lustre-client [11039.709987] Lustre: Unmounted lustre-client [11042.455479] Key type lgssc unregistered [11042.676721] LNet: 361825:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11043.746882] LNet: Removed LNI 192.168.202.35@tcp [11044.329633] Key type .llcrypt unregistered [11044.331396] Key type ._llcrypt unregistered [11045.134891] alg: No test for adler32 (adler32-zlib) [11045.926476] Key type ._llcrypt registered [11045.932793] Key type .llcrypt registered [11046.205324] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11046.472935] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11046.670258] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11046.673706] LNet: Accept secure, port 988 [11048.343190] Key type lgssc registered [11049.465869] Lustre: Echo OBD driver; http://www.lustre.org/ [11060.927797] Lustre: DEBUG MARKER: Iteration 27 [11061.328312] LustreError: 362614:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11061.341446] LustreError: 362617:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11061.370161] LustreError: 362614:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4980 [11062.483442] Lustre: Mounted lustre-client [11064.450460] Lustre: Unmounted lustre-client [11068.198487] Key type lgssc unregistered [11068.370939] LNet: 362971:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11069.426160] LNet: Removed LNI 192.168.202.35@tcp [11070.337291] Key type .llcrypt unregistered [11070.339198] Key type ._llcrypt unregistered [11071.297562] alg: No test for adler32 (adler32-zlib) [11072.063325] Key type ._llcrypt registered [11072.070481] Key type .llcrypt registered [11072.337228] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11072.574745] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11072.836965] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11072.846475] LNet: Accept secure, port 988 [11074.559110] Key type lgssc registered [11076.263716] Lustre: Echo OBD driver; http://www.lustre.org/ [11090.258732] Lustre: DEBUG MARKER: Iteration 28 [11090.870151] LustreError: 363766:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11090.871429] LustreError: 363767:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11090.888732] LustreError: 363766:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [11091.966190] Lustre: Mounted lustre-client [11093.766702] Lustre: Unmounted lustre-client [11097.003968] Key type lgssc unregistered [11097.298619] LNet: 364115:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11098.337791] LNet: Removed LNI 192.168.202.35@tcp [11099.408657] Key type .llcrypt unregistered [11099.410440] Key type ._llcrypt unregistered [11100.481668] alg: No test for adler32 (adler32-zlib) [11101.251879] Key type ._llcrypt registered [11101.258909] Key type .llcrypt registered [11101.565694] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11101.923175] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11102.252789] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11102.258692] LNet: Accept secure, port 988 [11103.927433] Key type lgssc registered [11105.241499] Lustre: Echo OBD driver; http://www.lustre.org/ [11117.568691] Lustre: DEBUG MARKER: Iteration 29 [11117.924187] LustreError: 364912:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11117.929193] LustreError: 364911:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11117.935151] LustreError: 364912:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4995 [11119.042498] Lustre: Mounted lustre-client [11120.653943] Lustre: Unmounted lustre-client [11124.123317] Key type lgssc unregistered [11124.405648] LNet: 365264:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11125.473032] LNet: Removed LNI 192.168.202.35@tcp [11126.312293] Key type .llcrypt unregistered [11126.318625] Key type ._llcrypt unregistered [11127.831109] alg: No test for adler32 (adler32-zlib) [11128.618512] Key type ._llcrypt registered [11128.627593] Key type .llcrypt registered [11128.814068] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11129.148749] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11129.697938] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11129.706406] LNet: Accept secure, port 988 [11131.456220] Key type lgssc registered [11133.222771] Lustre: Echo OBD driver; http://www.lustre.org/ [11146.691901] Lustre: DEBUG MARKER: Iteration 30 [11147.166824] LustreError: 366060:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11147.168589] LustreError: 366061:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11147.187901] LustreError: 366060:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [11148.216631] Lustre: Mounted lustre-client [11149.965699] Lustre: Unmounted lustre-client [11153.337386] Key type lgssc unregistered [11153.629543] LNet: 366410:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11154.659831] LNet: Removed LNI 192.168.202.35@tcp [11155.365233] Key type .llcrypt unregistered [11155.367572] Key type ._llcrypt unregistered [11156.053848] alg: No test for adler32 (adler32-zlib) [11156.838823] Key type ._llcrypt registered [11156.840906] Key type .llcrypt registered [11157.104312] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11157.462632] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11157.682855] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11157.690167] LNet: Accept secure, port 988 [11159.383151] Key type lgssc registered [11160.472352] Lustre: Echo OBD driver; http://www.lustre.org/ [11171.952528] Lustre: DEBUG MARKER: Iteration 31 [11172.305078] LustreError: 367199:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11172.307773] LustreError: 367208:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11172.318093] LustreError: 367199:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [11173.329292] Lustre: Mounted lustre-client [11174.532406] Lustre: Unmounted lustre-client [11176.614788] Key type lgssc unregistered [11176.803096] LNet: 367561:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11177.823959] LNet: Removed LNI 192.168.202.35@tcp [11178.405715] Key type .llcrypt unregistered [11178.408905] Key type ._llcrypt unregistered [11179.183018] alg: No test for adler32 (adler32-zlib) [11179.939466] Key type ._llcrypt registered [11179.941221] Key type .llcrypt registered [11180.127300] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11180.416604] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11180.644378] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11180.648463] LNet: Accept secure, port 988 [11182.311123] Key type lgssc registered [11183.665487] Lustre: Echo OBD driver; http://www.lustre.org/ [11195.482599] Lustre: DEBUG MARKER: Iteration 32 [11195.952831] LustreError: 368355:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11195.956313] LustreError: 368356:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11195.962801] LustreError: 368355:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [11197.095603] Lustre: Mounted lustre-client [11197.095603] Lustre: Mounted lustre-client [11199.972261] Lustre: Unmounted lustre-client [11203.243436] Key type lgssc unregistered [11203.544144] LNet: 368709:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11204.585719] LNet: Removed LNI 192.168.202.35@tcp [11205.345875] Key type .llcrypt unregistered [11205.348153] Key type ._llcrypt unregistered [11206.271763] alg: No test for adler32 (adler32-zlib) [11207.070541] Key type ._llcrypt registered [11207.072474] Key type .llcrypt registered [11207.253683] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11207.559693] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11208.079154] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11208.093611] LNet: Accept secure, port 988 [11210.031251] Key type lgssc registered [11211.567804] Lustre: Echo OBD driver; http://www.lustre.org/ [11226.502234] Lustre: DEBUG MARKER: Iteration 33 [11227.104628] LustreError: 369507:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11227.105530] LustreError: 369506:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11227.121897] LustreError: 369507:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4985 [11228.143542] Lustre: Mounted lustre-client [11229.934600] Lustre: Unmounted lustre-client [11232.814966] Key type lgssc unregistered [11233.033495] LNet: 369857:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11234.080868] LNet: Removed LNI 192.168.202.35@tcp [11235.137437] Key type .llcrypt unregistered [11235.142669] Key type ._llcrypt unregistered [11236.320326] alg: No test for adler32 (adler32-zlib) [11237.077643] Key type ._llcrypt registered [11237.083323] Key type .llcrypt registered [11237.409478] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11237.843315] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11238.302433] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11238.311278] LNet: Accept secure, port 988 [11240.007131] Key type lgssc registered [11241.184552] Lustre: Echo OBD driver; http://www.lustre.org/ [11254.254372] Lustre: DEBUG MARKER: Iteration 34 [11254.637723] LustreError: 370652:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11254.640457] LustreError: 370654:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11254.659819] LustreError: 370652:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [11255.694916] Lustre: Mounted lustre-client [11257.342058] Lustre: Unmounted lustre-client [11260.177557] Key type lgssc unregistered [11260.485363] LNet: 371006:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11261.549685] LNet: Removed LNI 192.168.202.35@tcp [11262.316216] Key type .llcrypt unregistered [11262.319669] Key type ._llcrypt unregistered [11263.328154] alg: No test for adler32 (adler32-zlib) [11264.089652] Key type ._llcrypt registered [11264.092670] Key type .llcrypt registered [11264.363437] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11264.660554] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11264.851960] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11264.856809] LNet: Accept secure, port 988 [11266.537278] Key type lgssc registered [11267.880760] Lustre: Echo OBD driver; http://www.lustre.org/ [11279.094255] Lustre: DEBUG MARKER: Iteration 35 [11279.500256] LustreError: 371797:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11279.501699] LustreError: 371799:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11279.525943] LustreError: 371797:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [11280.649703] Lustre: Mounted lustre-client [11280.658708] Lustre: Skipped 1 previous similar message [11282.598572] Lustre: Unmounted lustre-client [11285.862454] Key type lgssc unregistered [11286.188521] LNet: 372153:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11287.271761] LNet: Removed LNI 192.168.202.35@tcp [11288.102149] Key type .llcrypt unregistered [11288.114856] Key type ._llcrypt unregistered [11289.008204] alg: No test for adler32 (adler32-zlib) [11289.774874] Key type ._llcrypt registered [11289.777247] Key type .llcrypt registered [11289.999213] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11290.300495] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11290.679854] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11290.684267] LNet: Accept secure, port 988 [11292.479233] Key type lgssc registered [11293.714945] Lustre: Echo OBD driver; http://www.lustre.org/ [11305.826527] Lustre: DEBUG MARKER: Iteration 36 [11306.281223] LustreError: 372947:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11306.291575] LustreError: 372948:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11306.313747] LustreError: 372947:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4978 [11307.357789] Lustre: Mounted lustre-client [11309.203438] Lustre: Unmounted lustre-client [11311.947069] Key type lgssc unregistered [11312.283090] LNet: 373296:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11313.313429] LNet: Removed LNI 192.168.202.35@tcp [11314.086914] Key type .llcrypt unregistered [11314.091947] Key type ._llcrypt unregistered [11315.249808] alg: No test for adler32 (adler32-zlib) [11316.017675] Key type ._llcrypt registered [11316.025978] Key type .llcrypt registered [11316.231672] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11316.512462] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11316.698772] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11316.705393] LNet: Accept secure, port 988 [11318.447254] Key type lgssc registered [11319.786949] Lustre: Echo OBD driver; http://www.lustre.org/ [11332.482046] Lustre: DEBUG MARKER: Iteration 37 [11332.917511] LustreError: 374087:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11332.945422] LustreError: 374099:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11332.951328] LustreError: 374087:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4973 [11333.950919] Lustre: Mounted lustre-client [11335.388256] Lustre: Unmounted lustre-client [11338.213475] Key type lgssc unregistered [11338.440376] LNet: 374443:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11339.491183] LNet: Removed LNI 192.168.202.35@tcp [11340.194554] Key type .llcrypt unregistered [11340.197479] Key type ._llcrypt unregistered [11341.046463] alg: No test for adler32 (adler32-zlib) [11341.885331] Key type ._llcrypt registered [11341.891861] Key type .llcrypt registered [11342.357802] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11342.760149] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11343.034726] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11343.046886] LNet: Accept secure, port 988 [11344.727137] Key type lgssc registered [11345.772983] Lustre: Echo OBD driver; http://www.lustre.org/ [11357.041747] Lustre: DEBUG MARKER: Iteration 38 [11357.470242] LustreError: 375237:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11357.472565] LustreError: 375240:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11357.497991] LustreError: 375237:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4985 [11358.713955] Lustre: Mounted lustre-client [11358.718221] Lustre: Skipped 1 previous similar message [11359.790547] Lustre: Unmounted lustre-client [11360.313151] Lustre: Unmounted lustre-client [11364.440787] Key type lgssc unregistered [11364.775907] LNet: 375593:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11365.798118] LNet: Removed LNI 192.168.202.35@tcp [11366.746984] Key type .llcrypt unregistered [11366.749587] Key type ._llcrypt unregistered [11368.180233] alg: No test for adler32 (adler32-zlib) [11368.946826] Key type ._llcrypt registered [11368.952475] Key type .llcrypt registered [11369.457305] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11370.105532] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11370.506472] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11370.517182] LNet: Accept secure, port 988 [11372.367116] Key type lgssc registered [11374.206772] Lustre: Echo OBD driver; http://www.lustre.org/ [11390.261892] Lustre: DEBUG MARKER: Iteration 39 [11390.889810] LustreError: 376386:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11390.890414] LustreError: 376387:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11390.917427] LustreError: 376386:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [11392.102615] Lustre: Mounted lustre-client [11394.677658] Lustre: Unmounted lustre-client [11399.273538] Key type lgssc unregistered [11399.692926] LNet: 376739:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11400.738562] LNet: Removed LNI 192.168.202.35@tcp [11401.771038] Key type .llcrypt unregistered [11401.776129] Key type ._llcrypt unregistered [11402.921042] alg: No test for adler32 (adler32-zlib) [11403.684547] Key type ._llcrypt registered [11403.687280] Key type .llcrypt registered [11403.962881] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11404.159292] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11404.406780] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11404.409500] LNet: Accept secure, port 988 [11406.136135] Key type lgssc registered [11408.596853] Lustre: Echo OBD driver; http://www.lustre.org/ [11423.708522] Lustre: DEBUG MARKER: Iteration 40 [11424.159480] LustreError: 377535:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11424.160463] LustreError: 377536:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11424.178437] LustreError: 377535:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4982 [11425.368035] Lustre: Mounted lustre-client [11426.648636] Lustre: Unmounted lustre-client [11429.271887] Key type lgssc unregistered [11429.543812] LNet: 377888:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11430.560918] LNet: Removed LNI 192.168.202.35@tcp [11431.339862] Key type .llcrypt unregistered [11431.349473] Key type ._llcrypt unregistered [11432.399629] alg: No test for adler32 (adler32-zlib) [11433.225256] Key type ._llcrypt registered [11433.226631] Key type .llcrypt registered [11433.452151] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11433.899686] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11434.118415] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11434.124628] LNet: Accept secure, port 988 [11435.835232] Key type lgssc registered [11437.250425] Lustre: Echo OBD driver; http://www.lustre.org/ [11450.841770] Lustre: DEBUG MARKER: Iteration 41 [11451.298466] LustreError: 378683:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11451.307419] LustreError: 378685:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11451.320879] LustreError: 378683:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [11452.410808] Lustre: Mounted lustre-client [11454.085798] Lustre: Unmounted lustre-client [11457.257481] Key type lgssc unregistered [11457.497317] LNet: 379035:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11458.537149] LNet: Removed LNI 192.168.202.35@tcp [11459.450966] Key type .llcrypt unregistered [11459.453046] Key type ._llcrypt unregistered [11460.072226] alg: No test for adler32 (adler32-zlib) [11460.829470] Key type ._llcrypt registered [11460.831350] Key type .llcrypt registered [11460.989137] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11461.332454] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11461.534712] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11461.542918] LNet: Accept secure, port 988 [11463.240181] Key type lgssc registered [11464.817866] Lustre: Echo OBD driver; http://www.lustre.org/ [11477.411736] Lustre: DEBUG MARKER: Iteration 42 [11478.095312] LustreError: 379828:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11478.102085] LustreError: 379832:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11478.120403] LustreError: 379828:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4982 [11479.341731] Lustre: Mounted lustre-client [11481.685752] Lustre: Unmounted lustre-client [11485.492483] Key type lgssc unregistered [11485.720183] LNet: 380181:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11486.760503] LNet: Removed LNI 192.168.202.35@tcp [11487.843701] Key type .llcrypt unregistered [11487.849599] Key type ._llcrypt unregistered [11489.564969] alg: No test for adler32 (adler32-zlib) [11490.335461] Key type ._llcrypt registered [11490.342882] Key type .llcrypt registered [11490.676400] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11491.083558] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11491.412262] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11491.415747] LNet: Accept secure, port 988 [11493.199839] Key type lgssc registered [11494.658793] Lustre: Echo OBD driver; http://www.lustre.org/ [11508.668572] Lustre: DEBUG MARKER: Iteration 43 [11509.381229] LustreError: 380978:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11509.399935] LustreError: 380979:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11509.420452] LustreError: 380978:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4982 [11510.674740] Lustre: Mounted lustre-client [11513.555161] Lustre: Unmounted lustre-client [11517.429867] Key type lgssc unregistered [11517.806246] LNet: 381328:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11518.880845] LNet: Removed LNI 192.168.202.35@tcp [11520.286772] Key type .llcrypt unregistered [11520.289786] Key type ._llcrypt unregistered [11521.641398] alg: No test for adler32 (adler32-zlib) [11522.507901] Key type ._llcrypt registered [11522.509506] Key type .llcrypt registered [11522.971274] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11523.305840] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11523.652347] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11523.656711] LNet: Accept secure, port 988 [11525.343198] Key type lgssc registered [11527.545533] Lustre: Echo OBD driver; http://www.lustre.org/ [11539.970423] Lustre: DEBUG MARKER: Iteration 44 [11540.507350] LustreError: 382124:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11540.509639] LustreError: 382125:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11540.524418] LustreError: 382124:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [11541.507570] Lustre: Mounted lustre-client [11542.980883] Lustre: Unmounted lustre-client [11545.742933] Key type lgssc unregistered [11545.971046] LNet: 382477:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11547.042579] LNet: Removed LNI 192.168.202.35@tcp [11547.548882] Key type .llcrypt unregistered [11547.552905] Key type ._llcrypt unregistered [11548.501743] alg: No test for adler32 (adler32-zlib) [11549.287329] Key type ._llcrypt registered [11549.292688] Key type .llcrypt registered [11549.549325] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11549.902961] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11550.084150] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11550.089608] LNet: Accept secure, port 988 [11551.759163] Key type lgssc registered [11553.411711] Lustre: Echo OBD driver; http://www.lustre.org/ [11565.666329] Lustre: DEBUG MARKER: Iteration 45 [11566.008539] LustreError: 383273:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11566.008776] LustreError: 383270:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11566.022201] LustreError: 383273:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [11566.973374] Lustre: Mounted lustre-client [11568.485152] Lustre: Unmounted lustre-client [11570.717085] Key type lgssc unregistered [11570.909498] LNet: 383623:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11571.936674] LNet: Removed LNI 192.168.202.35@tcp [11572.777734] Key type .llcrypt unregistered [11572.784994] Key type ._llcrypt unregistered [11573.755508] alg: No test for adler32 (adler32-zlib) [11574.566638] Key type ._llcrypt registered [11574.573746] Key type .llcrypt registered [11574.776653] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11575.091215] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11575.303465] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11575.307891] LNet: Accept secure, port 988 [11577.039308] Key type lgssc registered [11578.493546] Lustre: Echo OBD driver; http://www.lustre.org/ [11593.033642] Lustre: DEBUG MARKER: Iteration 46 [11593.348385] LustreError: 384418:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11593.352819] LustreError: 384419:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11593.361883] LustreError: 384418:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [11594.351821] Lustre: Mounted lustre-client [11594.359092] Lustre: Skipped 1 previous similar message [11595.698030] Lustre: Unmounted lustre-client [11598.025205] Key type lgssc unregistered [11598.246125] LNet: 384769:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11599.329281] LNet: Removed LNI 192.168.202.35@tcp [11600.068717] Key type .llcrypt unregistered [11600.070927] Key type ._llcrypt unregistered [11601.092428] alg: No test for adler32 (adler32-zlib) [11601.875068] Key type ._llcrypt registered [11601.876802] Key type .llcrypt registered [11602.160067] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11602.497170] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11602.827512] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11602.832116] LNet: Accept secure, port 988 [11604.551246] Key type lgssc registered [11605.666446] Lustre: Echo OBD driver; http://www.lustre.org/ [11617.018677] Lustre: DEBUG MARKER: Iteration 47 [11617.404806] LustreError: 385565:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11617.406131] LustreError: 385567:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11617.417814] LustreError: 385565:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [11618.562678] Lustre: Mounted lustre-client [11619.917659] Lustre: Unmounted lustre-client [11622.337202] Key type lgssc unregistered [11622.531585] LNet: 385918:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11623.589859] LNet: Removed LNI 192.168.202.35@tcp [11624.147610] Key type .llcrypt unregistered [11624.150201] Key type ._llcrypt unregistered [11625.398832] alg: No test for adler32 (adler32-zlib) [11626.157369] Key type ._llcrypt registered [11626.162778] Key type .llcrypt registered [11626.408529] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11626.723701] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11626.895893] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11626.898748] LNet: Accept secure, port 988 [11628.551214] Key type lgssc registered [11629.576390] Lustre: Echo OBD driver; http://www.lustre.org/ [11642.268608] Lustre: DEBUG MARKER: Iteration 48 [11642.546774] LustreError: 386712:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11642.553187] LustreError: 386713:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11642.567808] LustreError: 386712:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [11643.627944] Lustre: Mounted lustre-client [11645.047789] Lustre: Unmounted lustre-client [11648.060951] Key type lgssc unregistered [11648.366423] LNet: 387067:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11649.447690] LNet: Removed LNI 192.168.202.35@tcp [11650.090886] Key type .llcrypt unregistered [11650.092861] Key type ._llcrypt unregistered [11650.955052] alg: No test for adler32 (adler32-zlib) [11651.720577] Key type ._llcrypt registered [11651.722580] Key type .llcrypt registered [11651.881078] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11652.158190] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11652.330316] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11652.335813] LNet: Accept secure, port 988 [11654.015132] Key type lgssc registered [11655.081620] Lustre: Echo OBD driver; http://www.lustre.org/ [11667.635343] Lustre: DEBUG MARKER: Iteration 49 [11667.945679] LustreError: 387865:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11667.947192] LustreError: 387866:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11667.978229] LustreError: 387865:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [11669.008501] Lustre: Mounted lustre-client [11670.938645] Lustre: Unmounted lustre-client [11673.568803] Key type lgssc unregistered [11673.981339] LNet: 388218:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11675.041710] LNet: Removed LNI 192.168.202.35@tcp [11676.046780] Key type .llcrypt unregistered [11676.051420] Key type ._llcrypt unregistered [11677.148894] alg: No test for adler32 (adler32-zlib) [11677.990307] Key type ._llcrypt registered [11677.993064] Key type .llcrypt registered [11678.308837] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11678.634937] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11678.978730] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11678.986720] LNet: Accept secure, port 988 [11680.735931] Key type lgssc registered [11683.307556] Lustre: Echo OBD driver; http://www.lustre.org/ [11698.309479] Lustre: DEBUG MARKER: Iteration 50 [11699.027314] LustreError: 389014:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11699.031513] LustreError: 389015:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11699.046051] LustreError: 389014:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [11700.243207] Lustre: Mounted lustre-client [11702.467339] Lustre: Unmounted lustre-client [11707.468647] Key type lgssc unregistered [11707.900509] LNet: 389368:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11708.961407] LNet: Removed LNI 192.168.202.35@tcp [11709.498435] Key type .llcrypt unregistered [11709.499883] Key type ._llcrypt unregistered [11710.768229] alg: No test for adler32 (adler32-zlib) [11711.528783] Key type ._llcrypt registered [11711.531066] Key type .llcrypt registered [11711.883855] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11712.352995] Lustre: Lustre: Build Version: 2.15.8_1_g00e7d23 [11712.788330] LNet: Added LNI 192.168.202.35@tcp [8/256/0/180] [11712.793792] LNet: Accept secure, port 988 [11714.616090] Key type lgssc registered [11716.025814] Lustre: Echo OBD driver; http://www.lustre.org/ [11729.015096] Lustre: Mounted lustre-client [11729.549544] Lustre: Mounted lustre-client [11735.697798] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 20:30:05 (1776213005) [11744.224911] Lustre: 390678:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776213008/real 1776213008] req@0000000064208af1 x1862494305916352/t0(0) o36->lustre-MDT0000-mdc-ffff93ebc4c10000@192.168.202.135@tcp:12/10 lens 496/440 e 0 to 1 dl 1776213015 ref 2 fl Rpc:XQr/0/ffffffff rc 0/-1 job:'ln.0' [11744.253975] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection to lustre-MDT0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [11744.302084] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection restored to 192.168.202.135@tcp (at 192.168.202.135@tcp) [11751.391436] Lustre: 390678:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776213015/real 1776213015] req@0000000064208af1 x1862494305916352/t0(0) o36->lustre-MDT0000-mdc-ffff93ebc4c10000@192.168.202.135@tcp:12/10 lens 496/440 e 0 to 1 dl 1776213022 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11751.442257] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection to lustre-MDT0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [11751.481328] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection restored to 192.168.202.135@tcp (at 192.168.202.135@tcp) [11758.561406] Lustre: 390678:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776213022/real 1776213022] req@0000000064208af1 x1862494305916352/t0(0) o36->lustre-MDT0000-mdc-ffff93ebc4c10000@192.168.202.135@tcp:12/10 lens 496/440 e 0 to 1 dl 1776213029 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11758.613554] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection to lustre-MDT0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [11758.666119] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection restored to 192.168.202.135@tcp (at 192.168.202.135@tcp) [11765.727473] Lustre: 390678:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776213030/real 1776213030] req@0000000064208af1 x1862494305916352/t0(0) o36->lustre-MDT0000-mdc-ffff93ebc4c10000@192.168.202.135@tcp:12/10 lens 496/440 e 0 to 1 dl 1776213037 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11765.743475] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection to lustre-MDT0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [11765.767895] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection restored to 192.168.202.135@tcp (at 192.168.202.135@tcp) [11772.895561] Lustre: 390678:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1776213037/real 1776213037] req@0000000064208af1 x1862494305916352/t0(0) o36->lustre-MDT0000-mdc-ffff93ebc4c10000@192.168.202.135@tcp:12/10 lens 496/440 e 0 to 1 dl 1776213044 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11772.935062] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection to lustre-MDT0000 (at 192.168.202.135@tcp) was lost; in progress operations using this service will wait for recovery to complete [11772.974296] Lustre: lustre-MDT0000-mdc-ffff93ebc4c10000: Connection restored to 192.168.202.135@tcp (at 192.168.202.135@tcp) [11778.853320] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 20:30:48 (1776213048) [11791.151409] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 20:31:00 (1776213060) [11804.924197] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 20:31:14 (1776213074) [11812.148928] Lustre: DEBUG MARKER: cleanup: ====================================================== [11814.346269] Lustre: DEBUG MARKER: == sanityn test complete, duration 11560 sec ============= 20:31:24 (1776213084) [12050.466896] Lustre: Unmounted lustre-client [12053.219298] Lustre: Unmounted lustre-client [12102.934739] Key type lgssc unregistered [12103.129434] LNet: 393967:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [12104.163964] LNet: Removed LNI 192.168.202.35@tcp [12105.034098] Key type .llcrypt unregistered [12105.039875] Key type ._llcrypt unregistered