[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffd9fff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffda000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 456231474 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.988 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54d0-0x000f54df] [ 0.000000] RAMDISK: [mem 0xbcc64000-0xbffcffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52F0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2464 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2300 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022C0 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2374 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE2404 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE243C 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2300-0xbffe2373] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22ff] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2374-0xbffe2403] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe2404-0xbffe243b] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe243c-0xbffe2463] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4744 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059618 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829700K/4306400K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001013] APIC: Switch to symmetric I/O mode setup [ 0.003162] x2apic enabled [ 0.004009] Switched APIC routing to physical x2apic. [ 0.005017] kvm-guest: setup PV IPIs [ 0.008000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x22982c12b6d, max_idle_ns: 440795281273 ns [ 0.008020] Calibrating delay loop (skipped) preset value.. 4799.97 BogoMIPS (lpj=2399988) [ 0.009010] pid_max: default: 32768 minimum: 301 [ 0.011057] LSM: Security Framework initializing [ 0.012045] Yama: becoming mindful. [ 0.013032] SELinux: Initializing. [ 0.014064] *** VALIDATE selinux *** [ 0.022498] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026761] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028147] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029119] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030108] *** VALIDATE tmpfs *** [ 0.032306] *** VALIDATE proc *** [ 0.033201] *** VALIDATE cgroup *** [ 0.034009] *** VALIDATE cgroup2 *** [ 0.036117] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037149] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.038009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.039027] Spectre V2 : User space: Vulnerable [ 0.040009] Speculative Store Bypass: Vulnerable [ 0.043014] debug: unmapping init [mem 0xffffffff95259000-0xffffffff95260fff] [ 0.045923] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046595] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.047020] ... version: 2 [ 0.048010] ... bit width: 48 [ 0.049010] ... generic registers: 4 [ 0.050010] ... value mask: 0000ffffffffffff [ 0.051009] ... max period: 00007fffffffffff [ 0.052037] ... fixed-purpose events: 3 [ 0.053009] ... event mask: 000000070000000f [ 0.055216] rcu: Hierarchical SRCU implementation. [ 0.057407] smp: Bringing up secondary CPUs ... [ 0.058644] x86: Booting SMP configuration: [ 0.059022] .... node #0, CPUs: #1 #2 #3 [ 0.062122] smp: Brought up 1 node, 4 CPUs [ 0.063997] smpboot: Max logical packages: 1 [ 0.065016] smpboot: Total of 4 processors activated (19199.90 BogoMIPS) [ 0.197264] node 0 deferred pages initialised in 130ms [ 0.200019] devtmpfs: initialized [ 0.201188] x86/mm: Memory block size: 128MB [ 0.203605] gcov: version magic: 0x41383552 [ 0.205099] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.207071] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.208353] pinctrl core: initialized pinctrl subsystem [ 0.210116] [ 0.210391] ************************************************************* [ 0.212012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.214010] ** ** [ 0.215007] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.216016] ** ** [ 0.218016] ** This means that this kernel is built to expose internal ** [ 0.221015] ** IOMMU data structures, which may compromise security on ** [ 0.223009] ** your system. ** [ 0.225011] ** ** [ 0.227010] ** If you see this message and you are not debugging the ** [ 0.228009] ** kernel, report this immediately to your vendor! ** [ 0.230011] ** ** [ 0.232010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.234011] ************************************************************* [ 0.236592] NET: Registered protocol family 16 [ 0.238372] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.240052] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.242051] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.245160] cpuidle: using governor menu [ 0.246761] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.248453] PCI: Using configuration type 1 for base access [ 0.251130] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.261117] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.262018] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.264051] cryptd: max_cpu_qlen set to 1000 [ 0.267264] ACPI: Added _OSI(Module Device) [ 0.269015] ACPI: Added _OSI(Processor Device) [ 0.270031] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.275028] ACPI: Added _OSI(Processor Aggregator Device) [ 0.280000] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.287535] ACPI: Interpreter enabled [ 0.288042] ACPI: PM: (supports S0 S3 S4 S5) [ 0.290021] ACPI: Using IOAPIC for interrupt routing [ 0.292139] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.295413] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.305420] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.307039] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.310019] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.313084] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.318084] acpiphp: Slot [2] registered [ 0.319113] acpiphp: Slot [5] registered [ 0.321218] acpiphp: Slot [6] registered [ 0.323160] acpiphp: Slot [3] registered [ 0.325107] acpiphp: Slot [4] registered [ 0.326164] acpiphp: Slot [7] registered [ 0.328136] acpiphp: Slot [8] registered [ 0.330118] acpiphp: Slot [9] registered [ 0.331119] acpiphp: Slot [10] registered [ 0.333139] acpiphp: Slot [11] registered [ 0.335128] acpiphp: Slot [12] registered [ 0.336109] acpiphp: Slot [13] registered [ 0.338129] acpiphp: Slot [14] registered [ 0.339179] acpiphp: Slot [15] registered [ 0.341154] acpiphp: Slot [16] registered [ 0.343126] acpiphp: Slot [17] registered [ 0.344133] acpiphp: Slot [18] registered [ 0.346125] acpiphp: Slot [19] registered [ 0.347137] acpiphp: Slot [20] registered [ 0.349152] acpiphp: Slot [21] registered [ 0.351165] acpiphp: Slot [22] registered [ 0.353110] acpiphp: Slot [23] registered [ 0.354143] acpiphp: Slot [24] registered [ 0.356106] acpiphp: Slot [25] registered [ 0.357101] acpiphp: Slot [26] registered [ 0.359109] acpiphp: Slot [27] registered [ 0.360068] acpiphp: Slot [28] registered [ 0.362131] acpiphp: Slot [29] registered [ 0.364093] acpiphp: Slot [30] registered [ 0.365134] acpiphp: Slot [31] registered [ 0.367064] PCI host bridge to bus 0000:00 [ 0.368014] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.371017] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.372014] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.377024] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.379018] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.382059] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.383139] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.386639] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.389369] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.396575] pci 0000:00:01.1: reg 0x20: [io 0xc120-0xc12f] [ 0.401100] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.403018] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.405019] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.406015] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.409586] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.412690] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.415047] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.418536] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.423013] pci 0000:00:02.0: reg 0x10: [io 0xc100-0xc11f] [ 0.435014] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.439018] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.445675] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.451910] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.459016] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.474015] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.483589] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.492016] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.501022] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.529026] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.542661] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.544331] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.546300] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.548380] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.551213] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.556157] iommu: Default domain type: Passthrough [ 0.557319] SCSI subsystem initialized [ 0.558000] ACPI: bus type USB registered [ 0.559101] usbcore: registered new interface driver usbfs [ 0.561099] usbcore: registered new interface driver hub [ 0.562073] usbcore: registered new device driver usb [ 0.564151] pps_core: LinuxPPS API ver. 1 registered [ 0.565008] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.568103] PTP clock support registered [ 0.570152] EDAC MC: Ver: 3.0.0 [ 0.572120] PCI: Using ACPI for IRQ routing [ 0.573628] NetLabel: Initializing [ 0.575012] NetLabel: domain hash size = 128 [ 0.576011] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.579082] NetLabel: unlabeled traffic allowed by default [ 0.581139] vgaarb: loaded [ 0.583266] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.584016] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.592035] clocksource: Switched to clocksource kvm-clock [ 0.693373] VFS: Disk quotas dquot_6.6.0 [ 0.694874] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.697700] *** VALIDATE ramfs *** [ 0.698817] *** VALIDATE hugetlbfs *** [ 0.700806] pnp: PnP ACPI init [ 0.703136] pnp: PnP ACPI: found 6 devices [ 0.719535] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.722680] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.724708] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.726798] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.729098] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.731533] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.734615] NET: Registered protocol family 2 [ 0.736781] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.740994] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.744135] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.748891] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.751949] TCP: Hash tables configured (established 65536 bind 65536) [ 0.754468] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.757085] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.759517] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.762157] NET: Registered protocol family 1 [ 0.766254] RPC: Registered named UNIX socket transport module. [ 0.768852] RPC: Registered udp transport module. [ 0.770612] RPC: Registered tcp transport module. [ 0.772392] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.775060] NET: Registered protocol family 44 [ 0.777027] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.779524] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.781807] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.784877] PCI: CLS 0 bytes, default 64 [ 0.786861] Unpacking initramfs... [ 2.230806] debug: unmapping init [mem 0xffff9d0f3cc64000-0xffff9d0f3ffcffff] [ 2.234854] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.237208] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.239956] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x22982c12b6d, max_idle_ns: 440795281273 ns [ 2.744244] Initialise system trusted keyrings [ 2.746018] Key type blacklist registered [ 2.751337] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.760599] zbud: loaded [ 2.764028] *** VALIDATE nfs *** [ 2.766472] *** VALIDATE nfs4 *** [ 2.768288] pstore: using deflate compression [ 2.775295] Platform Keyring initialized [ 2.898747] NET: Registered protocol family 38 [ 2.900600] Key type asymmetric registered [ 2.902279] Asymmetric key parser 'x509' registered [ 2.904483] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.908180] io scheduler mq-deadline registered [ 2.909677] io scheduler kyber registered [ 2.911288] io scheduler bfq registered [ 2.912861] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.915407] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.917791] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.920735] ACPI: Power Button [PWRF] [ 2.926472] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.934260] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.950893] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.977281] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.006687] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.011145] Non-volatile memory driver v1.3 [ 3.012602] Linux agpgart interface v0.103 [ 3.041981] virtio_blk virtio1: [vda] 68008 512-byte logical blocks (34.8 MB/33.2 MiB) [ 3.044380] vda: detected capacity change from 0 to 34820096 [ 3.063922] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.066976] vdb: detected capacity change from 0 to 1073741824 [ 3.075279] libphy: Fixed MDIO Bus: probed [ 3.082136] usbcore: registered new interface driver usbserial_generic [ 3.084666] usbserial: USB Serial support registered for generic [ 3.086555] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.091034] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.095195] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.099311] mousedev: PS/2 mouse device common for all mice [ 3.103050] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.105832] rtc_cmos 00:05: RTC can wake from S4 [ 3.110143] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.110562] rtc_cmos 00:05: registered as rtc0 [ 3.119412] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.121441] intel_pstate: CPU model not supported [ 3.123134] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.127809] hid: raw HID events driver (C) Jiri Kosina [ 3.129415] usbcore: registered new interface driver usbhid [ 3.130810] usbhid: USB HID core driver [ 3.132060] drop_monitor: Initializing network drop monitor service [ 3.133780] Initializing XFRM netlink socket [ 3.135366] NET: Registered protocol family 10 [ 3.137903] Segment Routing with IPv6 [ 3.140231] NET: Registered protocol family 17 [ 3.143452] mpls_gso: MPLS GSO support [ 3.150086] RAS: Correctable Errors collector initialized. [ 3.152647] AVX version of gcm_enc/dec engaged. [ 3.154461] AES CTR mode by8 optimization enabled [ 3.243707] sched_clock: Marking stable (3243618265, 0)->(4128672884, -885054619) [ 3.247685] registered taskstats version 1 [ 3.250730] Loading compiled-in X.509 certificates [ 3.254119] zswap: loaded using pool lzo/zbud [ 3.284205] Key type big_key registered [ 3.296920] Key type encrypted registered [ 3.299222] ima: No TPM chip found, activating TPM-bypass! [ 3.302721] ima: Allocated hash algorithm: sha1 [ 3.305608] ima: No architecture policies found [ 3.308670] evm: Initialising EVM extended attributes: [ 3.312115] evm: security.selinux [ 3.313884] evm: security.ima [ 3.315534] evm: security.capability [ 3.317462] evm: HMAC attrs: 0x1 [ 3.320532] rtc_cmos 00:05: setting system clock to 2026-06-12 16:06:26 UTC (1781280386) [ 3.328341] debug: unmapping init [mem 0xffffffff96203000-0xffffffff963fffff] [ 3.332461] debug: unmapping init [mem 0xffffffff94f82000-0xffffffff95258fff] [ 3.343166] Write protecting the kernel read-only data: 28672k [ 3.347821] debug: unmapping init [mem 0xffffffff93603000-0xffffffff937fffff] [ 3.351929] debug: unmapping init [mem 0xffffffff93f14000-0xffffffff93ffffff] [ 3.387414] 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.398300] systemd[1]: Detected virtualization kvm. [ 3.400171] systemd[1]: Detected architecture x86-64. [ 3.402144] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.429952] systemd[1]: No hostname configured. [ 3.431716] systemd[1]: Set hostname to . [ 3.434761] random: systemd: uninitialized urandom read (16 bytes read) [ 3.438140] systemd[1]: Initializing machine ID from random generator. [ 3.491728] random: ln: uninitialized urandom read (6 bytes read) [ 3.577866] random: systemd: uninitialized urandom read (16 bytes read) [ 3.581563] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 3.589470] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 3.594992] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Slices. [ OK ] Listening on Journal Socket. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Swap. [ OK ] Reached target Paths. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Local Encrypted Volumes. Starting Journal Service... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Timers. Starting Setup Virtual Console... [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Journal Service. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.240377] device-mapper: uevent: version 1.0.3 [ 4.242423] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 5.000482] virtio_net virtio0 ens2: renamed from eth0 [ 5.018379] scsi host0: ata_piix [ 5.045244] scsi host1: ata_piix [ 5.046885] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc120 irq 14 [ 5.049876] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc128 irq 15 [ 7.102784] random: fast init done [ 8.803778] dracut-initqueue[580]: RTNETLINK answers: File exists [ 9.824326] random: crng init done [ 9.825532] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 10.354157] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ 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.583502] printk: systemd: 25 output lines suppressed due to ratelimiting [ 11.853745] SELinux: Disabled at runtime. [ 11.951129] 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.962365] systemd[1]: Detected virtualization kvm. [ 11.964817] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.507197] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.511731] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.517601] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.522293] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.527151] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.537674] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.557550] systemd[1]: Mounting Kernel Debug File System... Mounting Kernel Debug File System... Starting Remount Root and Kernel File Systems... Mounting Huge Pages File System... [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root 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. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-getty.slice. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target rpc_pipefs.target. [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice User and Session Slice. Starting Apply Kernel Variables... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. Starting udev Coldplug all Devices... [ OK ] Reached target Slices. Activating swap /dev/disk/by-label/SWAP... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Mounting POSIX Message Queue File System... [ 12.742803] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [ 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 ] Mounted Huge Pages File System. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 13.070456] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 13.403210] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 13.491474] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.525508] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.544726] EDAC sbridge: Ver: 1.1.2 [ 14.856686] Key type dns_resolver registered [ 15.161700] NFS: Registering the id_resolver key type [ 15.163420] Key type id_resolver registered [ 15.165039] 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 Create Volatile Files and Directories... Starting Mark the need to relabel after reboot... [ 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 ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... Starting Restore /run/initramfs on shutdown... Starting Login Service... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ 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 Notify NFS peers of a restart... Starting Crash recovery kernel arming... Starting System Logging Service... [ 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 oleg457-client login: [ 44.765361] libcfs: loading out-of-tree module taints kernel. [ 44.833863] alg: No test for adler32 (adler32-zlib) [ 45.595464] Key type ._llcrypt registered [ 45.597189] Key type .llcrypt registered [ 45.769894] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [ 46.061596] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [ 46.420670] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [ 46.423064] LNet: Accept secure, port 988 [ 48.063143] Key type lgssc registered [ 48.773478] Lustre: Echo OBD driver; http://www.lustre.org/ [ 171.100086] hrtimer: interrupt took 6116739 ns [ 197.639659] Lustre: Mounted lustre-client [ 204.120451] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 223.200267] Lustre: lustre-OST0000-osc-ffff9d0f84f84000: disconnect after 23s idle [ 223.715624] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing check_logdir /tmp/testlogs/ [ 230.962849] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing yml_node [ 236.924471] Lustre: DEBUG MARKER: Client: 2.15.8.2 [ 240.586165] Lustre: DEBUG MARKER: MDS: 2.15.8.2 [ 243.921233] Lustre: DEBUG MARKER: OSS: 2.15.8.2 [ 245.938313] Lustre: DEBUG MARKER: -----============= acceptance-small: sanityn ============----- Fri Jun 12 12:10:27 EDT 2026 [ 255.334209] Lustre: DEBUG MARKER: excepting tests: 27 28 102 [ 256.932398] Lustre: DEBUG MARKER: skipping tests SLOW=no: 33a [ 257.997947] Lustre: Mounted lustre-client [ 265.847316] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing check_config_client /mnt/lustre [ 297.794882] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 311.735464] Lustre: DEBUG MARKER: == sanityn test 1: Check attribute updates on 2 mount points ========================================================== 12:11:32 (1781280692) [ 320.136662] Lustre: DEBUG MARKER: == sanityn test 2a: check cached attribute updates on 2 mtpt's ================================================================== 12:11:41 (1781280701) [ 329.007109] Lustre: DEBUG MARKER: == sanityn test 2b: check cached attribute updates on 2 mtpt's ================================================================== 12:11:50 (1781280710) [ 337.151536] Lustre: DEBUG MARKER: == sanityn test 2c: check cached attribute updates on 2 mtpt's root ============================================================= 12:11:58 (1781280718) [ 345.129408] Lustre: DEBUG MARKER: == sanityn test 2d: check cached attribute updates on 2 mtpt's root ============================================================= 12:12:06 (1781280726) [ 353.893719] Lustre: DEBUG MARKER: == sanityn test 2e: check chmod on root is propagated to others ========================================================== 12:12:15 (1781280735) [ 361.964258] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 12:12:23 (1781280743) [ 371.235790] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 12:12:32 (1781280752) [ 378.372903] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 12:12:39 (1781280759) [ 385.394601] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 12:12:47 (1781280767) [ 393.789125] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 12:12:55 (1781280775) [ 396.256149] Lustre: lustre-OST0000-osc-ffff9d0f84f84000: disconnect after 24s idle [ 396.261884] Lustre: Skipped 1 previous similar message [ 402.423990] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 12:13:03 (1781280783) [ 406.503112] Lustre: lustre-OST0001-osc-ffff9d0f8661c800: disconnect after 20s idle [ 409.417634] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 12:13:11 (1781280791) [ 416.712453] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 12:13:18 (1781280798) [ 423.688704] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 12:13:25 (1781280805) [ 431.490412] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 12:13:33 (1781280813) [ 438.019056] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 12:13:39 (1781280819) [ 446.673229] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 12:13:47 (1781280827) [ 454.511313] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 12:13:56 (1781280836) [ 464.604070] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 12:14:05 (1781280845) [ 466.608783] Lustre: DEBUG MARKER: start dir: /mnt/lustre/lockdir=144115205289279507 file: /mnt/lustre/lockdir/lockfile=144115205289279506 [ 608.838555] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 12:16:30 (1781280990) [ 617.570761] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 12:16:39 (1781280999) [ 625.282719] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 12:16:46 (1781281006) [ 632.737567] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 12:16:54 (1781281014) [ 642.293737] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 12:17:03 (1781281023) [ 650.691832] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 12:17:12 (1781281032) [ 652.964766] Lustre: DEBUG MARKER: chmod [ 660.658737] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 12:17:22 (1781281042) [ 669.205297] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7521280kB free gt MAXFREE 800000kB, increase 800000 (or reduce test fs size) to proceed [ 684.732701] Lustre: DEBUG MARKER: == sanityn test 16a: 500 iterations of dual-mount fsx ==== 12:17:46 (1781281066) [ 759.695500] Lustre: DEBUG MARKER: == sanityn test 16b: 500 iterations of dual-mount fsx at small size ========================================================== 12:19:01 (1781281141) [ 796.368861] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 12:19:37 (1781281177) [ 799.073221] Lustre: DEBUG MARKER: SKIP: sanityn test_16c dio on ldiskfs only [ 800.960021] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 12:19:42 (1781281182) [ 851.938428] Lustre: lustre-OST0001-osc-ffff9d0f8661c800: disconnect after 24s idle [ 858.574449] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 12:20:40 (1781281240) [ 867.748393] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 12:20:49 (1781281249) [ 869.178339] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.263074] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.339898] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.409721] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.516313] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.618364] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.689759] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.845188] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 869.972521] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.085058] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.198674] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.314947] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.491969] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.601742] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.736757] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.869793] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 870.987606] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.124489] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.221254] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.327671] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.429555] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.545766] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.642753] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.722864] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.812385] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 871.949939] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.069566] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.195305] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.296050] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.378720] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.461867] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.567428] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.675309] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.788927] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.886645] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 872.989973] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.078311] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.209928] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.308708] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.400544] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.500126] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.589876] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.678327] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.776775] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.886438] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 873.985616] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 874.076354] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 874.207673] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 874.318463] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 874.463835] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 874.642928] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 874.845902] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.003988] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.091319] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.179485] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.287963] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.386062] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.457559] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.584806] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.687285] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.782787] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.860798] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.921226] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 875.989680] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.051427] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.124657] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.194584] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.246679] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.323730] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.388304] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.447170] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.524442] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.588869] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.651970] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.767812] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.863027] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 876.956252] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.026715] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.094343] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.190830] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.269885] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.353983] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.453168] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.546605] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.683520] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.767237] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.826856] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 877.910368] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.010215] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.156456] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.253578] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.367277] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.451685] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.549410] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.630763] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.736944] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.806448] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.890564] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 878.978614] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.051805] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.157149] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.244960] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.293337] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.366748] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.431167] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.536670] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.647659] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.713740] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.774239] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.833939] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.894201] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 879.985737] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.073821] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.143587] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.202788] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.262039] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.320819] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.383617] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.453172] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.548672] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.621118] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.713842] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.780448] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.861463] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 880.959907] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.024316] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.085680] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.175213] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.257298] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.305171] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.362262] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.446103] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.527710] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.611697] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.689448] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.819955] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 881.918740] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.003210] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.106625] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.189889] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.311292] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.430819] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.533475] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.621855] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.655376] Lustre: lustre-OST0000-osc-ffff9d0f8661c800: disconnect after 23s idle [ 882.696793] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.788954] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.867114] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 882.991500] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.066927] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.168361] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.250946] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.322656] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.394724] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.476106] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.545115] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.625839] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.692177] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.771290] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.833457] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.902510] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 883.991326] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.066870] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.133924] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.210654] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.288553] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.353942] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.411869] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.485890] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.554899] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.634918] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.712976] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.855047] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 884.966028] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.087834] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.197041] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.314517] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.387781] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.487078] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.590550] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.687904] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.814667] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.904562] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 885.984434] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.081297] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.154694] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.224878] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.316432] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.387060] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.480572] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.604234] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.702558] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.795279] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.884622] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 886.974657] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.075652] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.150921] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.257177] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.316571] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.448438] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.604162] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.711158] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.794563] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 887.880129] rw_seq_cst_vs_d (28937): drop_caches: 3 [ 897.576149] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 12:21:18 (1781281278) [ 898.063091] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.166969] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.271271] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.470468] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.581577] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.650917] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.711949] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.856199] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 898.946402] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 899.411318] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 899.580093] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 899.679505] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 899.857431] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.020680] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.092465] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.198270] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.264145] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.390023] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.467899] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.709336] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.874778] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.927199] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 900.975151] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.054302] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.106346] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.274522] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.448233] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.514619] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.548389] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.622453] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.766384] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 901.981297] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.116113] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.252941] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.332267] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.411833] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.484266] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.623711] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.689567] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 902.896432] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 903.054864] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 903.163176] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 903.251989] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 903.411616] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 903.553347] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 903.860878] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 903.982749] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 904.101965] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 904.171669] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 904.223547] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 904.414223] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 904.626592] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 904.912823] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 904.998629] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 905.073453] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 905.341127] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 905.467702] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 905.522839] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 905.657868] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 905.780939] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 905.907275] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.045886] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.155946] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.199413] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.270019] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.420931] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.492640] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.612162] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.737731] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.789184] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 906.966912] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 907.049106] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 907.130770] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 907.214123] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 907.279468] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 907.383189] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 907.601690] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 907.784307] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.103322] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.261242] Lustre: lustre-OST0001-osc-ffff9d0f8661c800: disconnect after 20s idle [ 908.283052] Lustre: Skipped 1 previous similar message [ 908.302140] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.386816] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.442098] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.590526] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.711347] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.900050] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 908.940343] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.098908] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.151424] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.303374] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.379322] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.417253] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.537373] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.719758] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 909.914222] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.024936] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.158167] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.342529] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.371995] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.465266] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.594644] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.643644] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 910.859927] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.026198] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.094436] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.146213] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.328702] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.382688] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.484277] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.575190] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.796823] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 911.969199] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.099066] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.216265] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.277943] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.417511] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.516553] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.613962] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.786643] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.895132] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 912.960349] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 913.090493] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 913.302607] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 913.440192] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 913.662058] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 913.877963] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 913.935331] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 914.127646] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 914.197291] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 914.350409] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 914.414026] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 914.554767] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 914.735599] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 914.880598] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 915.086260] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 915.134413] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 915.257359] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 915.397329] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 915.525773] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 915.825989] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 915.916795] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.046334] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.161124] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.245954] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.329136] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.462989] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.622122] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.725306] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.809150] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.903865] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 916.971738] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 917.103250] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 917.226833] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 917.336468] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 917.488811] rw_seq_cst_vs_d (29519): drop_caches: 3 [ 928.876744] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 12:21:49 (1781281309) [ 937.099246] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 12:21:58 (1781281318) [ 938.977200] Lustre: lustre-OST0000-osc-ffff9d0f8661c800: disconnect after 22s idle [ 938.991126] Lustre: Skipped 1 previous similar message [ 948.098854] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 12:22:09 (1781281329) [ 974.973407] Lustre: DEBUG MARKER: == sanityn test 19: test concurrent uncached read races ========================================================================= 12:22:36 (1781281356) [ 978.081953] Lustre: DEBUG MARKER: SKIP: sanityn test_19 not cache-capable obdfilter [ 979.922714] Lustre: DEBUG MARKER: == sanityn test 20: test extra readahead page left in cache ============================================================== 12:22:41 (1781281361) [ 985.058071] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 20s idle [ 986.506388] Lustre: DEBUG MARKER: == sanityn test 21: Try to remove mountpoint on another dir ============================================================== 12:22:48 (1781281368) [ 994.649684] Lustre: DEBUG MARKER: == sanityn test 23: others should see updated atime while another read============================================================== 12:22:56 (1781281376) [ 1064.154388] Lustre: DEBUG MARKER: == sanityn test 24a: lfs df [-ih] [path] test =================================================================================== 12:24:05 (1781281445) [ 1070.767222] Lustre: DEBUG MARKER: == sanityn test 24b: lfs df should show both filesystems ========================================================================= 12:24:12 (1781281452) [ 1077.116976] Lustre: DEBUG MARKER: == sanityn test 25a: change ACL on one mountpoint be seen on another ============================================================= 12:24:18 (1781281458) [ 1084.919324] Lustre: DEBUG MARKER: == sanityn test 25b: change ACL under remote dir on one mountpoint be seen on another ========================================================== 12:24:26 (1781281466) [ 1093.344977] Lustre: DEBUG MARKER: == sanityn test 26a: allow mtime to get older ============ 12:24:34 (1781281474) [ 1102.274533] Lustre: DEBUG MARKER: == sanityn test 26b: sync mtime between ost and mds ====== 12:24:43 (1781281483) [ 1107.935355] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 25s idle [ 1107.943036] Lustre: Skipped 4 previous similar messages [ 1111.997380] Lustre: DEBUG MARKER: SKIP: sanityn test_27 skipping excluded test 27 [ 1114.183456] Lustre: DEBUG MARKER: SKIP: sanityn test_28 skipping ALWAYS excluded test 28 [ 1116.063508] Lustre: DEBUG MARKER: == sanityn test 30: recreate file race =================== 12:24:57 (1781281497) [ 1127.269172] Lustre: DEBUG MARKER: == sanityn test 31a: voluntary cancel / blocking ast race======================================================================== 12:25:08 (1781281508) [ 1128.154767] Lustre: *** cfs_fail_loc=314, val=0*** [ 1129.183403] Lustre: *** cfs_fail_loc=314, val=0*** [ 1129.193354] Lustre: Skipped 2 previous similar messages [ 1137.888859] Lustre: DEBUG MARKER: == sanityn test 31b: voluntary OST cancel / blocking ast race======================================================================== 12:25:19 (1781281519) [ 1152.201811] Lustre: *** cfs_fail_loc=314, val=0*** [ 1154.034266] Lustre: lustre-OST0000-osc-ffff9d0f8661c800: Connection to lustre-OST0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1154.066236] LustreError: lustre-OST0000-osc-ffff9d0f8661c800: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1154.093815] Lustre: lustre-OST0000-osc-ffff9d0f8661c800: Connection restored to (at 192.168.204.157@tcp) [ 1160.661876] Lustre: DEBUG MARKER: == sanityn test 31r: open-rename(replace) race =========== 12:25:42 (1781281542) [ 1160.926390] LustreError: 39814:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1419 sleeping for 3000ms [ 1163.977176] LustreError: 39814:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1419 awake [ 1170.354592] Lustre: DEBUG MARKER: SKIP: sanityn test_33a skipping SLOW test 33a [ 1172.094254] Lustre: DEBUG MARKER: == sanityn test 33b: COS: cross create/delete, 2 clients, benchmark under remote dir ========================================================== 12:25:53 (1781281553) [ 1174.159741] Lustre: DEBUG MARKER: SKIP: sanityn test_33b Need two or more clients, have 1 [ 1175.985474] Lustre: DEBUG MARKER: == sanityn test 33c: Cancel cross-MDT lock should trigger Sync-Lock-Cancel ========================================================== 12:25:57 (1781281557) [ 1179.641982] Lustre: lustre-MDT0000-mdc-ffff9d0f84f84000: Connection to lustre-MDT0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1186.787383] Lustre: 2257:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1781281562/real 1781281562] req@00000000f4d5f6bb x1867807910178432/t0(0) o400->MGC192.168.204.157@tcp@192.168.204.157@tcp:26/25 lens 224/224 e 0 to 1 dl 1781281569 ref 1 fl Rpc:XNQr/0/ffffffff rc 0/-1 job:'kworker/u8:2.0' [ 1186.813486] LustreError: 166-1: MGC192.168.204.157@tcp: Connection to MGS (at 192.168.204.157@tcp) was lost; in progress operations using this service will fail [ 1186.836752] Lustre: Evicted from MGS (at 192.168.204.157@tcp) after server handle changed from 0x7ceaa0b9f076a33f to 0x7ceaa0b9f07d0357 [ 1186.848883] Lustre: MGC192.168.204.157@tcp: Connection restored to (at 192.168.204.157@tcp) [ 1190.731162] Lustre: lustre-MDT0000-mdc-ffff9d0f8661c800: Connection restored to (at 192.168.204.157@tcp) [ 1215.218964] Lustre: DEBUG MARKER: == sanityn test 33d: DNE distributed operation should trigger COS ========================================================== 12:26:36 (1781281596) [ 1335.263442] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 21s idle [ 1335.274861] Lustre: Skipped 3 previous similar messages [ 1342.751204] Lustre: DEBUG MARKER: == sanityn test 33e: DNE local operation shouldn't trigger COS ========================================================== 12:28:44 (1781281724) [ 1344.257870] Lustre: DEBUG MARKER: SKIP: sanityn test_33e Need two or more clients, have 1 [ 1345.835707] Lustre: DEBUG MARKER: == sanityn test 34: no lock timeout under IO ============= 12:28:47 (1781281727) [ 1396.709347] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: Connection to lustre-OST0001 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1396.738513] Lustre: Skipped 1 previous similar message [ 1396.757565] LustreError: lustre-OST0001-osc-ffff9d0f84f84000: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1396.783631] LustreError: lustre-OST0001-osc-ffff9d0f8661c800: This client was evicted by lustre-OST0001; in progress operations using this service will fail. [ 1396.783997] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: Connection restored to (at 192.168.204.157@tcp) [ 1396.803519] Lustre: Skipped 2 previous similar messages [ 1400.769351] Lustre: lustre-OST0000-osc-ffff9d0f84f84000: Connection to lustre-OST0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1400.786709] Lustre: Skipped 1 previous similar message [ 1400.798241] LustreError: lustre-OST0000-osc-ffff9d0f84f84000: This client was evicted by lustre-OST0000; in progress operations using this service will fail. [ 1400.808863] Lustre: lustre-OST0000-osc-ffff9d0f84f84000: Connection restored to (at 192.168.204.157@tcp) [ 1424.397227] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9d0f84f84000.ost_server_uuid,osc.lustre-OST0000-osc-ffff9d0f8661c800.ost_server_uuid 40 [ 1425.982549] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9d0f84f84000.ost_server_uuid in IDLE state after 0 sec [ 1427.523683] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9d0f8661c800.ost_server_uuid in FULL state after 0 sec [ 1434.290549] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9d0f84f84000.ost_server_uuid,osc.lustre-OST0001-osc-ffff9d0f8661c800.ost_server_uuid 40 [ 1435.800967] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9d0f84f84000.ost_server_uuid in IDLE state after 0 sec [ 1437.551584] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9d0f8661c800.ost_server_uuid in IDLE state after 0 sec [ 1444.177697] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9d0f84f84000.ost_server_uuid,osc.lustre-OST0000-osc-ffff9d0f8661c800.ost_server_uuid 40 [ 1445.781603] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9d0f84f84000.ost_server_uuid in IDLE state after 0 sec [ 1447.343407] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9d0f8661c800.ost_server_uuid in FULL state after 0 sec [ 1452.729978] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9d0f84f84000.ost_server_uuid,osc.lustre-OST0001-osc-ffff9d0f8661c800.ost_server_uuid 40 [ 1454.215500] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9d0f84f84000.ost_server_uuid in IDLE state after 0 sec [ 1455.694120] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9d0f8661c800.ost_server_uuid in IDLE state after 0 sec [ 1465.743482] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff9d0f84f84000.ost_server_uuid,osc.lustre-OST0000-osc-ffff9d0f8661c800.ost_server_uuid 40 [ 1467.263665] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9d0f84f84000.ost_server_uuid in IDLE state after 0 sec [ 1468.730466] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff9d0f8661c800.ost_server_uuid in FULL state after 0 sec [ 1475.473989] Lustre: DEBUG MARKER: oleg457-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0001-osc-ffff9d0f84f84000.ost_server_uuid,osc.lustre-OST0001-osc-ffff9d0f8661c800.ost_server_uuid 40 [ 1477.222942] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9d0f84f84000.ost_server_uuid in IDLE state after 0 sec [ 1478.564436] Lustre: DEBUG MARKER: osc.lustre-OST0001-osc-ffff9d0f8661c800.ost_server_uuid in IDLE state after 0 sec [ 1480.438057] Lustre: DEBUG MARKER: == sanityn test 35: -EINTR cp_ast vs. bl_ast race does not evict client ========================================================== 12:31:02 (1781281862) [ 1483.920989] Lustre: DEBUG MARKER: Race attempt 0 [ 1486.788677] Lustre: DEBUG MARKER: Wait for 52332 52350 for 60 sec... [ 1553.366543] Lustre: DEBUG MARKER: == sanityn test 36: handle ESTALE/open-unlink correctly == 12:32:14 (1781281934) [ 1562.966086] Lustre: DEBUG MARKER: start test - cycle (0) [ 1589.821573] Lustre: DEBUG MARKER: start test - cycle (1) [ 1608.394086] Lustre: DEBUG MARKER: start test - cycle (2) [ 1634.239115] Lustre: DEBUG MARKER: start test - cycle (3) [ 1637.343285] Lustre: lustre-OST0001-osc-ffff9d0f8661c800: disconnect after 20s idle [ 1637.354303] Lustre: Skipped 4 previous similar messages [ 1660.564918] Lustre: DEBUG MARKER: start test - cycle (4) [ 1688.983053] Lustre: DEBUG MARKER: start test - cycle (5) [ 1716.517588] Lustre: DEBUG MARKER: start test - cycle (6) [ 1748.951808] Lustre: DEBUG MARKER: start test - cycle (7) [ 1767.070546] Lustre: DEBUG MARKER: start test - cycle (8) [ 1792.946323] Lustre: DEBUG MARKER: start test - cycle (9) [ 1819.110612] Lustre: DEBUG MARKER: start test - cycle (10) [ 1850.608643] Lustre: DEBUG MARKER: == sanityn test 37: check i_size is not updated for directory on close (bug 18695) ======================================================================== 12:37:12 (1781282232) [ 1945.315602] Lustre: DEBUG MARKER: == sanityn test 39a: test from 11063 ============================================================================================ 12:38:46 (1781282326) [ 1953.691727] Lustre: DEBUG MARKER: == sanityn test 39b: 11063 problem 1 ============================================================================================ 12:38:55 (1781282335) [ 1961.724353] Lustre: DEBUG MARKER: == sanityn test 39c: check truncate mtime update ================================================================================ 12:39:03 (1781282343) [ 1968.940558] Lustre: DEBUG MARKER: == sanityn test 39d: sync write should update mtime ====== 12:39:10 (1781282350) [ 1969.392809] Lustre: *** cfs_fail_loc=411, val=0*** [ 1976.888867] Lustre: DEBUG MARKER: == sanityn test 40a: pdirops: create vs others ======================================================================== 12:39:18 (1781282358) [ 1995.756973] Lustre: DEBUG MARKER: == sanityn test 40b: pdirops: open|create and others ======================================================================== 12:39:37 (1781282377) [ 2013.194457] Lustre: DEBUG MARKER: == sanityn test 40c: pdirops: link and others ======================================================================== 12:39:55 (1781282395) [ 2030.321958] Lustre: DEBUG MARKER: == sanityn test 40d: pdirops: unlink and others ======================================================================== 12:40:12 (1781282412) [ 2048.737393] Lustre: DEBUG MARKER: == sanityn test 40e: pdirops: rename and others ======================================================================== 12:40:30 (1781282430) [ 2066.412619] Lustre: DEBUG MARKER: == sanityn test 41a: pdirops: create vs mkdir ======================================================================== 12:40:47 (1781282447) [ 2081.289565] Lustre: DEBUG MARKER: == sanityn test 41b: pdirops: create vs create ======================================================================== 12:41:02 (1781282462) [ 2096.191039] Lustre: DEBUG MARKER: == sanityn test 41c: pdirops: create vs link ======================================================================== 12:41:17 (1781282477) [ 2108.846271] Lustre: DEBUG MARKER: == sanityn test 41d: pdirops: create vs unlink ======================================================================== 12:41:30 (1781282490) [ 2121.960386] Lustre: DEBUG MARKER: == sanityn test 41e: pdirops: create and rename (tgt) ======================================================================== 12:41:43 (1781282503) [ 2135.501434] Lustre: DEBUG MARKER: == sanityn test 41f: pdirops: create and rename (src) ======================================================================== 12:41:57 (1781282517) [ 2150.566972] Lustre: DEBUG MARKER: == sanityn test 41g: pdirops: create vs getattr ======================================================================== 12:42:12 (1781282532) [ 2154.464196] Lustre: lustre-OST0000-osc-ffff9d0f8661c800: disconnect after 22s idle [ 2154.467557] Lustre: Skipped 22 previous similar messages [ 2166.341779] Lustre: DEBUG MARKER: == sanityn test 41h: pdirops: create vs readdir ======================================================================== 12:42:27 (1781282547) [ 2180.372825] Lustre: DEBUG MARKER: == sanityn test 41i: reint_open: create vs create ======== 12:42:42 (1781282562) [ 3253.492682] Lustre: DEBUG MARKER: == sanityn test 42a: pdirops: mkdir vs mkdir ======================================================================== 13:00:34 (1781283634) [ 3268.181966] Lustre: DEBUG MARKER: == sanityn test 42b: pdirops: mkdir vs create ======================================================================== 13:00:49 (1781283649) [ 3283.128579] Lustre: DEBUG MARKER: == sanityn test 42c: pdirops: mkdir vs link ======================================================================== 13:01:04 (1781283664) [ 3298.045947] Lustre: DEBUG MARKER: == sanityn test 42d: pdirops: mkdir vs unlink ======================================================================== 13:01:19 (1781283679) [ 3310.579809] Lustre: DEBUG MARKER: == sanityn test 42e: pdirops: mkdir and rename (tgt) ======================================================================== 13:01:32 (1781283692) [ 3316.703324] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 21s idle [ 3316.715319] Lustre: Skipped 3 previous similar messages [ 3323.831672] Lustre: DEBUG MARKER: == sanityn test 42f: pdirops: mkdir and rename (src) ======================================================================== 13:01:45 (1781283705) [ 3338.228608] Lustre: DEBUG MARKER: == sanityn test 42g: pdirops: mkdir vs getattr ======================================================================== 13:01:59 (1781283719) [ 3352.390252] Lustre: DEBUG MARKER: == sanityn test 42h: pdirops: mkdir vs readdir ======================================================================== 13:02:14 (1781283734) [ 3371.901713] Lustre: DEBUG MARKER: == sanityn test 43a: rmdir,mkdir doesn't return -EEXIST ======================================================================== 13:02:33 (1781283753) [ 3569.335372] Lustre: DEBUG MARKER: == sanityn test 43b: pdirops: unlink vs create ======================================================================== 13:05:50 (1781283950) [ 3583.114879] Lustre: DEBUG MARKER: == sanityn test 43c: pdirops: unlink vs link ======================================================================== 13:06:04 (1781283964) [ 3596.902080] Lustre: DEBUG MARKER: == sanityn test 43d: pdirops: unlink vs unlink ======================================================================== 13:06:18 (1781283978) [ 3611.538215] Lustre: DEBUG MARKER: == sanityn test 43e: pdirops: unlink and rename (tgt) ======================================================================== 13:06:32 (1781283992) [ 3628.028578] Lustre: DEBUG MARKER: == sanityn test 43f: pdirops: unlink and rename (src) ======================================================================== 13:06:49 (1781284009) [ 3642.556933] Lustre: DEBUG MARKER: == sanityn test 43g: pdirops: unlink vs getattr ======================================================================== 13:07:04 (1781284024) [ 3661.493500] Lustre: DEBUG MARKER: == sanityn test 43h: pdirops: unlink vs readdir ======================================================================== 13:07:22 (1781284042) [ 3680.222746] Lustre: DEBUG MARKER: == sanityn test 43i: pdirops: unlink vs remote mkdir ===== 13:07:41 (1781284061) [ 3696.019796] Lustre: DEBUG MARKER: == sanityn test 43j: racy mkdir return EEXIST ======================================================================== 13:07:57 (1781284077) [ 3866.480906] Lustre: DEBUG MARKER: == sanityn test 43k: unlink vs create ==================== 13:10:47 (1781284247) [ 3987.423304] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 22s idle [ 3987.435033] Lustre: Skipped 7 previous similar messages [ 5225.082867] Lustre: DEBUG MARKER: == sanityn test 44a: pdirops: rename tgt vs mkdir ======================================================================== 13:33:26 (1781285606) [ 5231.583438] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 22s idle [ 5231.589978] Lustre: Skipped 4 previous similar messages [ 5238.082272] Lustre: DEBUG MARKER: == sanityn test 44b: pdirops: rename tgt vs create ======================================================================== 13:33:40 (1781285620) [ 5251.214177] Lustre: DEBUG MARKER: == sanityn test 44c: pdirops: rename tgt vs link ======================================================================== 13:33:52 (1781285632) [ 5265.706565] Lustre: DEBUG MARKER: == sanityn test 44d: pdirops: rename tgt vs unlink ======================================================================== 13:34:07 (1781285647) [ 5278.947818] Lustre: DEBUG MARKER: == sanityn test 44e: pdirops: rename tgt and rename (tgt) ======================================================================== 13:34:20 (1781285660) [ 5290.995573] Lustre: DEBUG MARKER: == sanityn test 44f: pdirops: rename tgt and rename (src) ======================================================================== 13:34:32 (1781285672) [ 5303.331512] Lustre: DEBUG MARKER: == sanityn test 44g: pdirops: rename tgt vs getattr ======================================================================== 13:34:45 (1781285685) [ 5313.504803] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 20s idle [ 5316.315959] Lustre: DEBUG MARKER: == sanityn test 44h: pdirops: rename tgt vs readdir ======================================================================== 13:34:58 (1781285698) [ 5329.267780] Lustre: DEBUG MARKER: == sanityn test 44i: pdirops: rename tgt vs remote mkdir ========================================================== 13:35:11 (1781285711) [ 5341.825726] Lustre: DEBUG MARKER: == sanityn test 45a: rename,mkdir doesn't return -EEXIST ======================================================================== 13:35:23 (1781285723) [ 5571.259734] Lustre: DEBUG MARKER: == sanityn test 45b: pdirops: rename src vs create ======================================================================== 13:39:13 (1781285953) [ 5588.571334] Lustre: DEBUG MARKER: == sanityn test 45c: pdirops: rename src vs link ======================================================================== 13:39:30 (1781285970) [ 5603.181645] Lustre: DEBUG MARKER: == sanityn test 45d: pdirops: rename src vs unlink ======================================================================== 13:39:44 (1781285984) [ 5615.597240] Lustre: DEBUG MARKER: == sanityn test 45e: pdirops: rename src and rename (tgt) ======================================================================== 13:39:57 (1781285997) [ 5628.886228] Lustre: DEBUG MARKER: == sanityn test 45f: pdirops: rename src and rename (src) ======================================================================== 13:40:10 (1781286010) [ 5641.956845] Lustre: DEBUG MARKER: == sanityn test 45g: pdirops: rename src vs getattr ======================================================================== 13:40:23 (1781286023) [ 5655.111342] Lustre: DEBUG MARKER: == sanityn test 45h: pdirops: unlink vs readdir ======================================================================== 13:40:37 (1781286037) [ 5667.694281] Lustre: DEBUG MARKER: == sanityn test 45i: pdirops: rename src vs remote mkdir ========================================================== 13:40:49 (1781286049) [ 5680.096290] Lustre: DEBUG MARKER: == sanityn test 45j: read vs rename ====================== 13:41:02 (1781286062) [ 5682.144396] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 20s idle [ 5682.148452] Lustre: Skipped 2 previous similar messages [ 7112.921950] Lustre: DEBUG MARKER: == sanityn test 46a: pdirops: link vs mkdir ======================================================================== 14:04:54 (1781287494) [ 7126.010608] Lustre: lustre-OST0000-osc-ffff9d0f84f84000: disconnect after 21s idle [ 7131.223864] Lustre: DEBUG MARKER: == sanityn test 46b: pdirops: link vs create ======================================================================== 14:05:12 (1781287512) [ 7144.802858] Lustre: DEBUG MARKER: == sanityn test 46c: pdirops: link vs link ======================================================================== 14:05:26 (1781287526) [ 7158.950814] Lustre: DEBUG MARKER: == sanityn test 46d: pdirops: link vs unlink ======================================================================== 14:05:40 (1781287540) [ 7174.324059] Lustre: DEBUG MARKER: == sanityn test 46e: pdirops: link and rename (tgt) ======================================================================== 14:05:56 (1781287556) [ 7177.183472] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 21s idle [ 7177.201515] Lustre: Skipped 2 previous similar messages [ 7189.283817] Lustre: DEBUG MARKER: == sanityn test 46f: pdirops: link and rename (src) ======================================================================== 14:06:10 (1781287570) [ 7203.391880] Lustre: DEBUG MARKER: == sanityn test 46g: pdirops: link vs getattr ======================================================================== 14:06:25 (1781287585) [ 7218.306471] Lustre: DEBUG MARKER: == sanityn test 46h: pdirops: link vs readdir ======================================================================== 14:06:39 (1781287599) [ 7232.795419] Lustre: DEBUG MARKER: == sanityn test 46i: pdirops: link vs remote mkdir ======= 14:06:54 (1781287614) [ 7246.976136] Lustre: DEBUG MARKER: == sanityn test 47a: pdirops: remote mkdir vs mkdir ====== 14:07:08 (1781287628) [ 7261.611785] Lustre: DEBUG MARKER: == sanityn test 47b: pdirops: remote mkdir vs create ===== 14:07:23 (1781287643) [ 7264.223456] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 21s idle [ 7264.241918] Lustre: Skipped 3 previous similar messages [ 7276.178384] Lustre: DEBUG MARKER: == sanityn test 47c: pdirops: remote mkdir vs link ======= 14:07:37 (1781287657) [ 7290.547482] Lustre: DEBUG MARKER: == sanityn test 47d: pdirops: remote mkdir vs unlink ===== 14:07:52 (1781287672) [ 7306.035898] Lustre: DEBUG MARKER: == sanityn test 47e: pdirops: remote mkdir and rename (tgt) ========================================================== 14:08:07 (1781287687) [ 7320.733963] Lustre: DEBUG MARKER: == sanityn test 47f: pdirops: remote mkdir and rename (src) ========================================================== 14:08:22 (1781287702) [ 7335.252385] Lustre: DEBUG MARKER: == sanityn test 47g: pdirops: remote mkdir vs getattr ==== 14:08:37 (1781287717) [ 7352.336307] Lustre: DEBUG MARKER: == sanityn test 50: osc lvb attrs: enqueue vs. CP AST ======================================================================== 14:08:53 (1781287733) [ 7352.844522] LustreError: 19252:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 410 sleeping for 2000ms [ 7354.943316] LustreError: 19252:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 410 awake [ 7365.356174] Lustre: DEBUG MARKER: == sanityn test 51a: layout lock: refresh layout should work ========================================================== 14:09:06 (1781287746) [ 7373.772859] Lustre: DEBUG MARKER: == sanityn test 51b: layout lock: glimpse should be able to restart if layout changed ========================================================== 14:09:15 (1781287755) [ 7374.106103] LustreError: 264025:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 7378.175174] LustreError: 264025:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 7378.201740] LustreError: 264025:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 7382.271167] LustreError: 264025:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 7382.324370] LustreError: 264031:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 sleeping for 4000ms [ 7386.391196] LustreError: 264031:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 1404 awake [ 7393.009886] Lustre: DEBUG MARKER: == sanityn test 51c: layout lock: IT_LAYOUT blocked and correct layout can be returned ========================================================== 14:09:34 (1781287774) [ 7404.562283] Lustre: DEBUG MARKER: == sanityn test 51d: layout lock: losing layout lock should clean up memory map region ========================================================== 14:09:46 (1781287786) [ 7412.061294] Lustre: DEBUG MARKER: == sanityn test 51e: lfs getstripe does not break leases, part 2 ========================================================== 14:09:53 (1781287793) [ 7419.738756] Lustre: DEBUG MARKER: == sanityn test 54: rename locking ======================= 14:10:01 (1781287801) [ 7453.492526] Lustre: DEBUG MARKER: == sanityn test 55a: rename vs unlink target dir ========= 14:10:35 (1781287835) [ 7466.624798] Lustre: DEBUG MARKER: == sanityn test 55b: rename vs unlink source dir ========= 14:10:48 (1781287848) [ 7480.789307] Lustre: DEBUG MARKER: == sanityn test 55c: rename vs unlink orphan target dir == 14:11:02 (1781287862) [ 7501.091142] Lustre: DEBUG MARKER: == sanityn test 55d: rename file vs link ================= 14:11:22 (1781287882) [ 7518.353291] Lustre: DEBUG MARKER: == sanityn test 60: Verify data_version behaviour ======== 14:11:39 (1781287899) [ 7528.221821] Lustre: DEBUG MARKER: == sanityn test 70a: cd directory [ 7536.083239] Lustre: DEBUG MARKER: == sanityn test 70b: remove files after calling rm_entry ========================================================== 14:11:57 (1781287917) [ 7545.747463] Lustre: DEBUG MARKER: == sanityn test 71a: correct file map just after write operation is finished ========================================================== 14:12:06 (1781287926) [ 7547.573096] Lustre: DEBUG MARKER: SKIP: sanityn test_71a ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 7549.924898] Lustre: DEBUG MARKER: == sanityn test 71b: check fiemap support for stripecount > 1 ========================================================== 14:12:11 (1781287931) [ 7552.843355] Lustre: DEBUG MARKER: SKIP: sanityn test_71b ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 7554.736739] Lustre: DEBUG MARKER: == sanityn test 71c: check FIEMAP_EXTENT_LAST flag with different extents number ========================================================== 14:12:16 (1781287936) [ 7557.022225] Lustre: DEBUG MARKER: SKIP: sanityn test_71c support only ldiskfs ost [ 7558.674446] Lustre: DEBUG MARKER: == sanityn test 71d: fiemap corruption test with fm_extent_count=0 ========================================================== 14:12:20 (1781287940) [ 7561.008569] Lustre: DEBUG MARKER: SKIP: sanityn test_71d ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 7562.895463] Lustre: DEBUG MARKER: == sanityn test 72: getxattr/setxattr cache should be consistent between nodes ========================================================== 14:12:24 (1781287944) [ 7570.091922] Lustre: DEBUG MARKER: == sanityn test 73: getxattr should not cause xattr lock cancellation ========================================================== 14:12:32 (1781287952) [ 7577.506449] Lustre: DEBUG MARKER: == sanityn test 74: flock deadlock: different mounts ======================================================================== 14:12:39 (1781287959) [ 7581.227981] LustreError: 11-0: lustre-MDT0000-mdc-ffff9d0f8661c800: operation ldlm_enqueue to node 192.168.204.157@tcp failed: rc = -35 [ 7589.041110] Lustre: DEBUG MARKER: == sanityn test 75: osc: upcall after unuse lock============================================================================= 14:12:50 (1781287970) [ 7589.660394] LustreError: 2257:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 31d sleeping for 2000ms [ 7591.759250] LustreError: 2257:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 31d awake [ 7602.106408] Lustre: DEBUG MARKER: == sanityn test 76: Verify MDT open_files listing ======== 14:13:03 (1781287983) [ 7612.383498] Lustre: lustre-OST0000-osc-ffff9d0f8661c800: disconnect after 23s idle [ 7612.395414] Lustre: Skipped 3 previous similar messages [ 7780.877480] Lustre: DEBUG MARKER: == sanityn test 77a: check FIFO NRS policy =============== 14:16:02 (1781288162) [ 7789.628960] Lustre: DEBUG MARKER: == sanityn test 77b: check CRR-N NRS policy ============== 14:16:11 (1781288171) [ 7803.402374] Lustre: DEBUG MARKER: == sanityn test 77c: check ORR NRS policy ================ 14:16:25 (1781288185) [ 7820.215969] Lustre: DEBUG MARKER: == sanityn test 77d: check TRR nrs policy ================ 14:16:42 (1781288202) [ 7835.366800] Lustre: DEBUG MARKER: == sanityn test 77e: check TBF NID nrs policy ============ 14:16:57 (1781288217) [ 7857.007693] Lustre: DEBUG MARKER: == sanityn test 77f: check TBF JobID nrs policy ========== 14:17:19 (1781288239) [ 7879.909844] Lustre: DEBUG MARKER: == sanityn test 77g: Change TBF type directly ============ 14:17:41 (1781288261) [ 7892.487511] Lustre: DEBUG MARKER: == sanityn test 77h: Wrong policy name should report error, not LBUG ========================================================== 14:17:53 (1781288273) [ 7905.312369] Lustre: DEBUG MARKER: == sanityn test 77i: Change rank of TBF rule ============= 14:18:06 (1781288286) [ 7929.408990] Lustre: DEBUG MARKER: == sanityn test 77j: check TBF-OPCode NRS policy ========= 14:18:31 (1781288311) [ 7955.431832] Lustre: lustre-OST0001-osc-ffff9d0f84f84000: disconnect after 23s idle [ 7955.443947] Lustre: Skipped 5 previous similar messages [ 7993.231973] Lustre: DEBUG MARKER: == sanityn test 77ja: check TBF-UID/GID NRS policy ======= 14:19:35 (1781288375) [ 8144.931280] Lustre: DEBUG MARKER: == sanityn test 77k: check TBF policy with NID/JobID/OPCode expression ========================================================== 14:22:06 (1781288526) [ 8580.064848] Lustre: lustre-OST0000-osc-ffff9d0f84f84000: disconnect after 24s idle [ 8580.081236] Lustre: Skipped 17 previous similar messages [ 8592.192872] Lustre: DEBUG MARKER: == sanityn test 77l: check the output of NRS policies for generic TBF ========================================================== 14:29:33 (1781288973) [ 8605.571837] Lustre: DEBUG MARKER: == sanityn test 77m: check NRS Delay slows write RPC processing ========================================================== 14:29:46 (1781288986) [ 8665.623907] Lustre: DEBUG MARKER: == sanityn test 77n: check wildcard support for TBF JobID NRS policy ========================================================== 14:30:46 (1781289046) [ 8758.702291] Lustre: DEBUG MARKER: == sanityn test 77o: Changing rank should not panic ====== 14:32:19 (1781289139) [ 8773.373362] Lustre: DEBUG MARKER: == sanityn test 77q: Parallel TBF rule definitions should not panic ========================================================== 14:32:34 (1781289154) [ 8894.201612] Lustre: DEBUG MARKER: == sanityn test 77p: Check validity of rule names for TBF policies ========================================================== 14:34:35 (1781289275) [ 8936.901232] Lustre: DEBUG MARKER: == sanityn test 78: Enable policy and specify tunings right away ========================================================== 14:35:17 (1781289317) [ 8949.115649] Lustre: DEBUG MARKER: == sanityn test 79: xattr: intent error ================== 14:35:30 (1781289330) [ 8970.358402] Lustre: DEBUG MARKER: == sanityn test 80a: migrate directory when some children is being opened ========================================================== 14:35:51 (1781289351) [ 8976.778168] LustreError: 300768:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff9d0f84f84000: inode [0x200000402:0x7b8:0x0] mdc close failed: rc = -116 [ 8977.452205] LustreError: 300772:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff9d0f84f84000: inode [0x240000402:0x5f2:0x0] mdc close failed: rc = -116 [ 8977.462205] LustreError: 300772:0:(file.c:246:ll_close_inode_openhandle()) Skipped 1 previous similar message [ 8991.247567] Lustre: DEBUG MARKER: == sanityn test 80b: Accessing directory during migration ========================================================== 14:36:12 (1781289372) [ 9010.636970] LustreError: 301480:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff9d0f84f84000: inode [0x240000402:0x627:0x0] mdc close failed: rc = -116 [ 9010.660471] LustreError: 301480:0:(file.c:246:ll_close_inode_openhandle()) Skipped 9 previous similar messages [ 9034.190400] LustreError: 301656:0:(file.c:246:ll_close_inode_openhandle()) lustre-clilmv-ffff9d0f8661c800: inode [0x200000402:0x7f8:0x0] mdc close failed: rc = -2 [ 9062.187546] Lustre: DEBUG MARKER: == sanityn test 81a: rename and stat under striped directory ========================================================== 14:37:23 (1781289443) [ 9074.875598] Lustre: DEBUG MARKER: == sanityn test 81b: rename under striped directory doesn't deadlock ========================================================== 14:37:36 (1781289456) [ 9281.158582] Lustre: DEBUG MARKER: == sanityn test 81c: rename revoke LOOKUP lock for remote object ========================================================== 14:41:02 (1781289662) [ 9283.033315] Lustre: DEBUG MARKER: SKIP: sanityn test_81c needs >= 4 MDTs [ 9285.101663] Lustre: DEBUG MARKER: == sanityn test 82: fsetxattr and fgetxattr on orphan files ========================================================== 14:41:06 (1781289666) [ 9292.816515] Lustre: DEBUG MARKER: == sanityn test 83: access striped directory while it is being created/unlinked ========================================================== 14:41:14 (1781289674) [ 9421.768073] Lustre: DEBUG MARKER: == sanityn test 84: 0-nlink race in lu_object_find() ===== 14:43:23 (1781289803) [ 9434.832842] Lustre: DEBUG MARKER: == sanityn test 90: open/create and unlink striped directory ========================================================== 14:43:36 (1781289816) [ 9622.267690] Lustre: DEBUG MARKER: == sanityn test 91: chmod and unlink striped directory === 14:46:43 (1781290003) [ 9810.124312] Lustre: DEBUG MARKER: == sanityn test 92: create remote directory under orphan directory ========================================================== 14:49:52 (1781290192) [ 9818.037548] Lustre: DEBUG MARKER: == sanityn test 93: alloc_rr should not allocate on same ost ========================================================== 14:49:59 (1781290199) [ 9836.701989] Lustre: DEBUG MARKER: == sanityn test 94: signal vs CP callback race =========== 14:50:18 (1781290218) [ 9837.386838] Lustre: DEBUG MARKER: write [ 9837.470796] LustreError: 31333:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 sleeping for 5000ms [ 9839.492473] Lustre: DEBUG MARKER: kill 312340 [ 9839.505819] LustreError: 312340:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 329 sleeping for 6000ms [ 9842.495129] LustreError: 31333:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 312 awake [ 9845.575236] LustreError: 312340:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 329 awake [ 9854.645296] Lustre: DEBUG MARKER: == sanityn test 95b: Check readpage() on a page that is no longer uptodate ========================================================== 14:50:35 (1781290235) [ 9855.145465] LustreError: 312938:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 1424 sleeping for 5000ms [ 9857.239151] LustreError: 312938:0:(fail.c:144:__cfs_fail_timeout_set()) cfs_fail_timeout interrupted [ 9868.629807] Lustre: DEBUG MARKER: == sanityn test 100a: DoM: glimpse RPCs for stat without IO lock (DoM only file) ========================================================== 14:50:50 (1781290250) [ 9870.440565] Lustre: DEBUG MARKER: SKIP: sanityn test_100a Reserved for glimpse-ahead [ 9872.529540] Lustre: DEBUG MARKER: == sanityn test 100b: DoM: no glimpse RPC for stat with IO lock (DoM only file) ========================================================== 14:50:54 (1781290254) [ 9880.621418] Lustre: DEBUG MARKER: == sanityn test 100c: DoM: write vs stat without IO lock (combined file) ========================================================== 14:51:02 (1781290262) [ 9888.187374] Lustre: DEBUG MARKER: == sanityn test 100d: DoM: write+truncate vs stat without IO lock (combined file) ========================================================== 14:51:09 (1781290269) [ 9895.455474] Lustre: DEBUG MARKER: == sanityn test 100e: DoM: read on open and file size ==== 14:51:17 (1781290277) [ 9902.142972] Lustre: DEBUG MARKER: == sanityn test 101a: Discard DoM data on unlink ========= 14:51:23 (1781290283) [ 9909.404358] Lustre: DEBUG MARKER: == sanityn test 101b: Discard DoM data on rename ========= 14:51:30 (1781290290) [ 9916.179308] Lustre: DEBUG MARKER: == sanityn test 101c: Discard DoM data on close-unlink === 14:51:38 (1781290298) [ 9924.122398] Lustre: DEBUG MARKER: SKIP: sanityn test_102 skipping ALWAYS excluded test 102 [ 9926.574118] Lustre: DEBUG MARKER: == sanityn test 103: Test size correctness with lockahead ========================================================== 14:51:47 (1781290307) [ 9928.632082] Lustre: *** cfs_fail_loc=415, val=0*** [ 9941.179631] Lustre: DEBUG MARKER: == sanityn test 104: Verify that MDS stores atime/mtime/ctime during close ========================================================== 14:52:02 (1781290322) [ 9942.833817] Lustre: DEBUG MARKER: SKIP: sanityn test_104 ldiskfs only test [ 9944.576631] Lustre: DEBUG MARKER: == sanityn test 105: Glimpse and lock cancel race ======== 14:52:06 (1781290326) [ 9945.021781] LustreError: 5708:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [ 9950.031182] LustreError: 5708:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 9955.055247] LustreError: 5708:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 9955.070731] LustreError: 5708:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [ 9955.089255] LustreError: 5708:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 9965.192096] LustreError: 5708:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 9965.202291] LustreError: 5708:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 1 previous similar message [ 9975.340101] LustreError: 31333:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [ 9975.346296] LustreError: 31333:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [ 9985.351176] LustreError: 31333:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [ 9985.360103] LustreError: 31333:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 3 previous similar messages [10010.703338] LustreError: 31333:0:(fail.c:138:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 sleeping for 5000ms [10010.717815] LustreError: 31333:0:(fail.c:138:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [10020.839190] LustreError: 31333:0:(fail.c:149:__cfs_fail_timeout_set()) cfs_fail_timeout id 416 awake [10020.850318] LustreError: 31333:0:(fail.c:149:__cfs_fail_timeout_set()) Skipped 6 previous similar messages [10027.655263] Lustre: DEBUG MARKER: == sanityn test 106a: Verify the btime via statx() ======= 14:53:29 (1781290409) [10029.178800] Lustre: DEBUG MARKER: SKIP: sanityn test_106a Test only for ldiskfs and statx() supported [10030.870134] Lustre: DEBUG MARKER: == sanityn test 106b: Glimpse RPCs test for statx ======== 14:53:32 (1781290412) [10038.046524] Lustre: DEBUG MARKER: == sanityn test 106c: Verify statx attributes mask ======= 14:53:39 (1781290419) [10045.787860] Lustre: DEBUG MARKER: == sanityn test 107a: Basic grouplock conflict =========== 14:53:47 (1781290427) [10054.664419] Lustre: DEBUG MARKER: == sanityn test 107b: Grouplock is added to the head of waiting list ========================================================== 14:53:56 (1781290436) [10067.541168] Lustre: DEBUG MARKER: == sanityn test 108a: lseek: parallel updates ============ 14:54:09 (1781290449) [10078.532463] Lustre: DEBUG MARKER: == sanityn test 109: Race with several mount instances on 1 node ========================================================== 14:54:20 (1781290460) [10081.789218] Lustre: Unmounted lustre-client [10086.124568] Lustre: Unmounted lustre-client [10087.734963] Lustre: DEBUG MARKER: Iteration 1 [10088.357758] LustreError: 323133:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10088.358253] LustreError: 323132:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10088.376195] LustreError: 323133:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4995 [10088.687669] Lustre: Mounted lustre-client [10090.882741] Lustre: Unmounted lustre-client [10095.131099] Key type lgssc unregistered [10095.658776] LNet: 323485:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10096.737947] LNet: Removed LNI 192.168.204.57@tcp [10097.893118] Key type .llcrypt unregistered [10097.897447] Key type ._llcrypt unregistered [10098.746544] alg: No test for adler32 (adler32-zlib) [10099.722094] Key type ._llcrypt registered [10099.724293] Key type .llcrypt registered [10100.512990] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10101.320380] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10102.210988] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10102.214769] LNet: Accept secure, port 988 [10104.044451] Key type lgssc registered [10106.078996] Lustre: Echo OBD driver; http://www.lustre.org/ [10118.120336] Lustre: DEBUG MARKER: Iteration 2 [10118.409220] LustreError: 324281:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10118.411894] LustreError: 324282:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10118.423128] LustreError: 324281:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4993 [10119.487707] Lustre: Mounted lustre-client [10121.097232] Lustre: Unmounted lustre-client [10123.698893] Key type lgssc unregistered [10123.929455] LNet: 324630:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10124.962577] LNet: Removed LNI 192.168.204.57@tcp [10125.639173] Key type .llcrypt unregistered [10125.643833] Key type ._llcrypt unregistered [10126.250224] alg: No test for adler32 (adler32-zlib) [10127.022431] Key type ._llcrypt registered [10127.024497] Key type .llcrypt registered [10127.228935] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10127.543373] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10127.798969] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10127.803906] LNet: Accept secure, port 988 [10129.471251] Key type lgssc registered [10130.643870] Lustre: Echo OBD driver; http://www.lustre.org/ [10142.362683] Lustre: DEBUG MARKER: Iteration 3 [10142.668689] LustreError: 325422:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10142.668898] LustreError: 325423:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10142.688080] LustreError: 325422:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4981 [10143.660333] Lustre: Mounted lustre-client [10145.080144] Lustre: Unmounted lustre-client [10148.078047] Key type lgssc unregistered [10148.311192] LNet: 325774:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10149.348967] LNet: Removed LNI 192.168.204.57@tcp [10149.918114] Key type .llcrypt unregistered [10149.924267] Key type ._llcrypt unregistered [10150.653831] alg: No test for adler32 (adler32-zlib) [10151.410465] Key type ._llcrypt registered [10151.412493] Key type .llcrypt registered [10151.613847] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10151.880233] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10152.075082] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10152.078976] LNet: Accept secure, port 988 [10153.743298] Key type lgssc registered [10154.712117] Lustre: Echo OBD driver; http://www.lustre.org/ [10164.624122] Lustre: DEBUG MARKER: Iteration 4 [10164.980404] LustreError: 326569:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10164.980495] LustreError: 326568:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10164.996777] LustreError: 326569:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [10165.994416] Lustre: Mounted lustre-client [10167.498281] Lustre: Unmounted lustre-client [10170.522567] Key type lgssc unregistered [10170.751967] LNet: 326922:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10171.812587] LNet: Removed LNI 192.168.204.57@tcp [10172.427886] Key type .llcrypt unregistered [10172.430510] Key type ._llcrypt unregistered [10173.129208] alg: No test for adler32 (adler32-zlib) [10173.927811] Key type ._llcrypt registered [10173.935239] Key type .llcrypt registered [10174.138541] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10174.452065] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10174.650773] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10174.653829] LNet: Accept secure, port 988 [10176.343758] Key type lgssc registered [10177.463590] Lustre: Echo OBD driver; http://www.lustre.org/ [10189.088733] Lustre: DEBUG MARKER: Iteration 5 [10189.495132] LustreError: 327717:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10189.495765] LustreError: 327718:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10189.519880] LustreError: 327717:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4983 [10190.585965] Lustre: Mounted lustre-client [10191.831808] Lustre: Unmounted lustre-client [10194.655954] Key type lgssc unregistered [10194.897816] LNet: 328067:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10195.970686] LNet: Removed LNI 192.168.204.57@tcp [10196.713041] Key type .llcrypt unregistered [10196.715590] Key type ._llcrypt unregistered [10197.696902] alg: No test for adler32 (adler32-zlib) [10198.454537] Key type ._llcrypt registered [10198.455992] Key type .llcrypt registered [10198.746150] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10199.200399] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10199.430349] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10199.434809] LNet: Accept secure, port 988 [10201.127216] Key type lgssc registered [10202.433785] Lustre: Echo OBD driver; http://www.lustre.org/ [10212.138898] Lustre: DEBUG MARKER: Iteration 6 [10212.437989] LustreError: 328861:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10212.440468] LustreError: 328862:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10212.459640] LustreError: 328861:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=5000 [10213.455916] Lustre: Mounted lustre-client [10215.079315] Lustre: Unmounted lustre-client [10217.672281] Key type lgssc unregistered [10217.868266] LNet: 329214:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10218.917571] LNet: Removed LNI 192.168.204.57@tcp [10219.403203] Key type .llcrypt unregistered [10219.404954] Key type ._llcrypt unregistered [10220.193915] alg: No test for adler32 (adler32-zlib) [10220.954418] Key type ._llcrypt registered [10220.962394] Key type .llcrypt registered [10221.164772] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10221.447731] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10221.673441] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10221.675409] LNet: Accept secure, port 988 [10223.295856] Key type lgssc registered [10224.368225] Lustre: Echo OBD driver; http://www.lustre.org/ [10234.034221] Lustre: DEBUG MARKER: Iteration 7 [10234.261224] LustreError: 330007:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10234.262601] LustreError: 330011:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10234.281025] LustreError: 330007:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [10235.243403] Lustre: Mounted lustre-client [10236.562735] Lustre: Unmounted lustre-client [10238.942239] Key type lgssc unregistered [10239.182849] LNet: 330361:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10240.233066] LNet: Removed LNI 192.168.204.57@tcp [10240.800894] Key type .llcrypt unregistered [10240.806889] Key type ._llcrypt unregistered [10241.453918] alg: No test for adler32 (adler32-zlib) [10242.243712] Key type ._llcrypt registered [10242.249113] Key type .llcrypt registered [10242.464242] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10242.705921] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10242.881023] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10242.889669] LNet: Accept secure, port 988 [10244.543138] Key type lgssc registered [10245.506656] Lustre: Echo OBD driver; http://www.lustre.org/ [10256.961096] Lustre: DEBUG MARKER: Iteration 8 [10257.383706] LustreError: 331158:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10257.385844] LustreError: 331159:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10257.405399] LustreError: 331158:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=5000 [10258.389700] Lustre: Mounted lustre-client [10258.396880] Lustre: Skipped 1 previous similar message [10259.881802] Lustre: Unmounted lustre-client [10262.654706] Key type lgssc unregistered [10262.950146] LNet: 331512:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10263.969078] LNet: Removed LNI 192.168.204.57@tcp [10264.569993] Key type .llcrypt unregistered [10264.574090] Key type ._llcrypt unregistered [10265.377277] alg: No test for adler32 (adler32-zlib) [10266.143914] Key type ._llcrypt registered [10266.147936] Key type .llcrypt registered [10266.340534] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10266.625231] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10266.829430] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10266.834620] LNet: Accept secure, port 988 [10268.472114] Key type lgssc registered [10269.539128] Lustre: Echo OBD driver; http://www.lustre.org/ [10278.934158] Lustre: DEBUG MARKER: Iteration 9 [10279.140824] LustreError: 332306:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10279.141046] LustreError: 332307:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10279.162904] LustreError: 332306:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [10280.127818] Lustre: Mounted lustre-client [10280.135114] Lustre: Skipped 1 previous similar message [10281.410337] Lustre: Unmounted lustre-client [10283.379449] Key type lgssc unregistered [10283.645719] LNet: 332658:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10284.704623] LNet: Removed LNI 192.168.204.57@tcp [10285.208530] Key type .llcrypt unregistered [10285.210841] Key type ._llcrypt unregistered [10285.793068] alg: No test for adler32 (adler32-zlib) [10286.552448] Key type ._llcrypt registered [10286.555514] Key type .llcrypt registered [10286.739567] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10287.044502] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10287.205911] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10287.209664] LNet: Accept secure, port 988 [10288.871319] Key type lgssc registered [10289.831780] Lustre: Echo OBD driver; http://www.lustre.org/ [10299.584778] Lustre: DEBUG MARKER: Iteration 10 [10299.854887] LustreError: 333453:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10299.855118] LustreError: 333454:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10299.873939] LustreError: 333453:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [10300.835750] Lustre: Mounted lustre-client [10302.340133] Lustre: Unmounted lustre-client [10304.881456] Key type lgssc unregistered [10305.152863] LNet: 333803:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10306.211599] LNet: Removed LNI 192.168.204.57@tcp [10306.906537] Key type .llcrypt unregistered [10306.909696] Key type ._llcrypt unregistered [10307.777809] alg: No test for adler32 (adler32-zlib) [10308.536350] Key type ._llcrypt registered [10308.537649] Key type .llcrypt registered [10308.698341] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10308.989730] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10309.184320] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10309.188840] LNet: Accept secure, port 988 [10310.872296] Key type lgssc registered [10312.065212] Lustre: Echo OBD driver; http://www.lustre.org/ [10322.537981] Lustre: DEBUG MARKER: Iteration 11 [10322.872945] LustreError: 334597:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10322.875142] LustreError: 334598:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10322.892072] LustreError: 334597:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [10323.889419] Lustre: Mounted lustre-client [10325.001234] Lustre: Unmounted lustre-client [10327.372030] Key type lgssc unregistered [10327.576407] LNet: 334945:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10328.608567] LNet: Removed LNI 192.168.204.57@tcp [10329.143873] Key type .llcrypt unregistered [10329.147202] Key type ._llcrypt unregistered [10329.913839] alg: No test for adler32 (adler32-zlib) [10330.668955] Key type ._llcrypt registered [10330.673116] Key type .llcrypt registered [10330.844415] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10331.049330] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10331.199336] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10331.201635] LNet: Accept secure, port 988 [10332.839094] Key type lgssc registered [10333.974465] Lustre: Echo OBD driver; http://www.lustre.org/ [10345.100857] Lustre: DEBUG MARKER: Iteration 12 [10345.505042] LustreError: 335742:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10345.509844] LustreError: 335743:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10345.523761] LustreError: 335742:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4995 [10346.509698] Lustre: Mounted lustre-client [10348.282275] Lustre: Unmounted lustre-client [10350.923837] Key type lgssc unregistered [10351.100254] LNet: 336095:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10352.162836] LNet: Removed LNI 192.168.204.57@tcp [10352.753586] Key type .llcrypt unregistered [10352.759627] Key type ._llcrypt unregistered [10353.329550] alg: No test for adler32 (adler32-zlib) [10354.088943] Key type ._llcrypt registered [10354.093018] Key type .llcrypt registered [10354.289308] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10354.613504] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10354.877671] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10354.880956] LNet: Accept secure, port 988 [10356.543145] Key type lgssc registered [10358.019044] Lustre: Echo OBD driver; http://www.lustre.org/ [10371.523753] Lustre: DEBUG MARKER: Iteration 13 [10372.202420] LustreError: 336891:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10372.219731] LustreError: 336890:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10372.239965] LustreError: 336891:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4980 [10373.386165] Lustre: Mounted lustre-client [10375.028410] Lustre: Unmounted lustre-client [10378.968935] Key type lgssc unregistered [10379.279494] LNet: 337244:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10380.327731] LNet: Removed LNI 192.168.204.57@tcp [10381.132483] Key type .llcrypt unregistered [10381.136347] Key type ._llcrypt unregistered [10382.005094] alg: No test for adler32 (adler32-zlib) [10382.758602] Key type ._llcrypt registered [10382.761869] Key type .llcrypt registered [10383.014754] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10383.380847] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10383.650328] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10383.659746] LNet: Accept secure, port 988 [10385.335152] Key type lgssc registered [10386.756953] Lustre: Echo OBD driver; http://www.lustre.org/ [10397.879834] Lustre: DEBUG MARKER: Iteration 14 [10398.210476] LustreError: 338034:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10398.212324] LustreError: 338038:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10398.226922] LustreError: 338034:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10399.280628] Lustre: Mounted lustre-client [10401.236697] Lustre: Unmounted lustre-client [10404.066553] Key type lgssc unregistered [10404.357819] LNet: 338389:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10405.408631] LNet: Removed LNI 192.168.204.57@tcp [10406.040799] Key type .llcrypt unregistered [10406.043589] Key type ._llcrypt unregistered [10406.872542] alg: No test for adler32 (adler32-zlib) [10407.645825] Key type ._llcrypt registered [10407.648309] Key type .llcrypt registered [10407.860945] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10408.142948] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10408.391034] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10408.400563] LNet: Accept secure, port 988 [10410.103157] Key type lgssc registered [10411.167173] Lustre: Echo OBD driver; http://www.lustre.org/ [10421.453340] Lustre: DEBUG MARKER: Iteration 15 [10422.037090] LustreError: 339183:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10422.038109] LustreError: 339184:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10422.057296] LustreError: 339183:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10423.094931] Lustre: Mounted lustre-client [10424.621594] Lustre: Unmounted lustre-client [10427.230787] Key type lgssc unregistered [10427.435700] LNet: 339531:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10427.449935] LNet: Removed LNI 192.168.204.57@tcp [10428.016466] Key type .llcrypt unregistered [10428.020499] Key type ._llcrypt unregistered [10428.842965] alg: No test for adler32 (adler32-zlib) [10429.603651] Key type ._llcrypt registered [10429.609143] Key type .llcrypt registered [10429.828886] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10430.124701] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10430.366924] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10430.373164] LNet: Accept secure, port 988 [10432.055135] Key type lgssc registered [10433.044925] Lustre: Echo OBD driver; http://www.lustre.org/ [10444.659585] Lustre: DEBUG MARKER: Iteration 16 [10444.928926] LustreError: 340325:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10444.930465] LustreError: 340324:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10444.945223] LustreError: 340325:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [10446.003638] Lustre: Mounted lustre-client [10447.573719] Lustre: Unmounted lustre-client [10449.797485] Key type lgssc unregistered [10450.020184] LNet: 340675:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10451.041675] LNet: Removed LNI 192.168.204.57@tcp [10451.570882] Key type .llcrypt unregistered [10451.577304] Key type ._llcrypt unregistered [10452.293418] alg: No test for adler32 (adler32-zlib) [10453.049358] Key type ._llcrypt registered [10453.053901] Key type .llcrypt registered [10453.291908] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10453.609558] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10453.837222] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10453.845134] LNet: Accept secure, port 988 [10455.583527] Key type lgssc registered [10456.778716] Lustre: Echo OBD driver; http://www.lustre.org/ [10465.925485] Lustre: DEBUG MARKER: Iteration 17 [10466.161170] LustreError: 341468:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10466.161763] LustreError: 341469:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10466.178166] LustreError: 341468:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [10467.084340] Lustre: Mounted lustre-client [10468.539024] Lustre: Unmounted lustre-client [10470.705341] Key type lgssc unregistered [10470.903273] LNet: 341821:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10471.973310] LNet: Removed LNI 192.168.204.57@tcp [10472.617828] Key type .llcrypt unregistered [10472.620280] Key type ._llcrypt unregistered [10474.025522] alg: No test for adler32 (adler32-zlib) [10474.784585] Key type ._llcrypt registered [10474.786729] Key type .llcrypt registered [10474.944350] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10475.181687] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10475.443235] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10475.447818] LNet: Accept secure, port 988 [10477.151364] Key type lgssc registered [10478.705574] Lustre: Echo OBD driver; http://www.lustre.org/ [10492.430845] Lustre: DEBUG MARKER: Iteration 18 [10492.929885] LustreError: 342626:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10492.932787] LustreError: 342627:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10492.966934] LustreError: 342626:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4980 [10494.055646] Lustre: Mounted lustre-client [10495.888238] Lustre: Unmounted lustre-client [10499.157268] Key type lgssc unregistered [10499.549330] LNet: 342980:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10500.587019] LNet: Removed LNI 192.168.204.57@tcp [10501.446570] Key type .llcrypt unregistered [10501.449514] Key type ._llcrypt unregistered [10502.449766] alg: No test for adler32 (adler32-zlib) [10503.221482] Key type ._llcrypt registered [10503.232551] Key type .llcrypt registered [10503.474478] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10503.731898] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10503.939542] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10503.943439] LNet: Accept secure, port 988 [10505.586666] Key type lgssc registered [10506.917809] Lustre: Echo OBD driver; http://www.lustre.org/ [10517.358381] Lustre: DEBUG MARKER: Iteration 19 [10517.651608] LustreError: 343772:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10517.652714] LustreError: 343774:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10517.666583] LustreError: 343772:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4994 [10518.686962] Lustre: Mounted lustre-client [10520.202161] Lustre: Unmounted lustre-client [10523.111093] Key type lgssc unregistered [10523.360489] LNet: 344124:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10524.386235] LNet: Removed LNI 192.168.204.57@tcp [10524.972185] Key type .llcrypt unregistered [10524.975984] Key type ._llcrypt unregistered [10525.633838] alg: No test for adler32 (adler32-zlib) [10526.400699] Key type ._llcrypt registered [10526.407407] Key type .llcrypt registered [10526.658932] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10526.951794] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10527.182872] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10527.189494] LNet: Accept secure, port 988 [10528.879596] Key type lgssc registered [10529.944424] Lustre: Echo OBD driver; http://www.lustre.org/ [10540.014544] Lustre: DEBUG MARKER: Iteration 20 [10540.310073] LustreError: 344917:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10540.315135] LustreError: 344916:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10540.330705] LustreError: 344917:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10541.454868] Lustre: Mounted lustre-client [10543.257746] Lustre: Unmounted lustre-client [10545.980255] Key type lgssc unregistered [10546.237797] LNet: 345271:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10547.312568] LNet: Removed LNI 192.168.204.57@tcp [10547.980463] Key type .llcrypt unregistered [10547.986339] Key type ._llcrypt unregistered [10548.772801] alg: No test for adler32 (adler32-zlib) [10549.545464] Key type ._llcrypt registered [10549.550243] Key type .llcrypt registered [10549.772258] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10550.036625] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10550.252219] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10550.262451] LNet: Accept secure, port 988 [10551.961865] Key type lgssc registered [10553.248752] Lustre: Echo OBD driver; http://www.lustre.org/ [10565.367635] Lustre: DEBUG MARKER: Iteration 21 [10565.799989] LustreError: 346061:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10565.815543] LustreError: 346071:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10565.849921] LustreError: 346061:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4968 [10567.073682] Lustre: Mounted lustre-client [10568.882130] Lustre: Unmounted lustre-client [10572.811097] Key type lgssc unregistered [10573.229246] LNet: 346420:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10574.318706] LNet: Removed LNI 192.168.204.57@tcp [10575.377913] Key type .llcrypt unregistered [10575.381047] Key type ._llcrypt unregistered [10576.328483] alg: No test for adler32 (adler32-zlib) [10577.207154] Key type ._llcrypt registered [10577.213122] Key type .llcrypt registered [10577.523960] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10577.999559] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10578.265494] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10578.278571] LNet: Accept secure, port 988 [10579.951321] Key type lgssc registered [10580.898741] Lustre: Echo OBD driver; http://www.lustre.org/ [10591.242864] Lustre: DEBUG MARKER: Iteration 22 [10591.528038] LustreError: 347216:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10591.529094] LustreError: 347217:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10591.545901] LustreError: 347216:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [10592.502820] Lustre: Mounted lustre-client [10593.755209] Lustre: Unmounted lustre-client [10596.153667] Key type lgssc unregistered [10596.355144] LNet: 347566:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10597.409303] LNet: Removed LNI 192.168.204.57@tcp [10598.022682] Key type .llcrypt unregistered [10598.025821] Key type ._llcrypt unregistered [10598.874539] alg: No test for adler32 (adler32-zlib) [10599.628445] Key type ._llcrypt registered [10599.630580] Key type .llcrypt registered [10599.859913] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10600.292862] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10600.494995] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10600.500502] LNet: Accept secure, port 988 [10602.199515] Key type lgssc registered [10603.371913] Lustre: Echo OBD driver; http://www.lustre.org/ [10614.533926] Lustre: DEBUG MARKER: Iteration 23 [10614.889992] LustreError: 348359:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10614.940144] LustreError: 348376:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10614.950668] LustreError: 348359:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4951 [10615.965920] Lustre: Mounted lustre-client [10615.970754] Lustre: Skipped 1 previous similar message [10617.452114] Lustre: Unmounted lustre-client [10620.037494] Key type lgssc unregistered [10620.341836] LNet: 348716:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10621.409592] LNet: Removed LNI 192.168.204.57@tcp [10622.035407] Key type .llcrypt unregistered [10622.039874] Key type ._llcrypt unregistered [10622.887745] alg: No test for adler32 (adler32-zlib) [10623.655409] Key type ._llcrypt registered [10623.661508] Key type .llcrypt registered [10623.893662] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10624.297034] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10624.561770] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10624.565249] LNet: Accept secure, port 988 [10626.218733] Key type lgssc registered [10627.503332] Lustre: Echo OBD driver; http://www.lustre.org/ [10639.001874] Lustre: DEBUG MARKER: Iteration 24 [10639.315016] LustreError: 349510:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10639.317100] LustreError: 349512:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10639.331891] LustreError: 349510:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [10640.344579] Lustre: Mounted lustre-client [10641.898715] Lustre: Unmounted lustre-client [10644.818449] Key type lgssc unregistered [10645.074789] LNet: 349864:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10646.113386] LNet: Removed LNI 192.168.204.57@tcp [10646.831930] Key type .llcrypt unregistered [10646.837281] Key type ._llcrypt unregistered [10647.998630] alg: No test for adler32 (adler32-zlib) [10648.756108] Key type ._llcrypt registered [10648.761138] Key type .llcrypt registered [10648.965283] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10649.334878] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10649.535591] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10649.540184] LNet: Accept secure, port 988 [10651.199281] Key type lgssc registered [10652.530608] Lustre: Echo OBD driver; http://www.lustre.org/ [10663.429936] Lustre: DEBUG MARKER: Iteration 25 [10663.865719] LustreError: 350659:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10663.869584] LustreError: 350660:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10663.889405] LustreError: 350659:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [10664.924353] Lustre: Mounted lustre-client [10664.935643] Lustre: Skipped 1 previous similar message [10666.584185] Lustre: Unmounted lustre-client [10669.194175] Key type lgssc unregistered [10669.447034] LNet: 351005:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10670.498130] LNet: Removed LNI 192.168.204.57@tcp [10671.113557] Key type .llcrypt unregistered [10671.115962] Key type ._llcrypt unregistered [10671.797317] alg: No test for adler32 (adler32-zlib) [10672.549498] Key type ._llcrypt registered [10672.551691] Key type .llcrypt registered [10672.747921] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10673.086936] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10673.300705] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10673.304371] LNet: Accept secure, port 988 [10674.943150] Key type lgssc registered [10676.250485] Lustre: Echo OBD driver; http://www.lustre.org/ [10687.868542] Lustre: DEBUG MARKER: Iteration 26 [10688.155523] LustreError: 351800:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10688.156189] LustreError: 351801:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10688.183708] LustreError: 351800:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4978 [10689.212353] Lustre: Mounted lustre-client [10689.216722] Lustre: Skipped 1 previous similar message [10690.531467] Lustre: Unmounted lustre-client [10692.947702] Key type lgssc unregistered [10693.160849] LNet: 352151:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10694.177145] LNet: Removed LNI 192.168.204.57@tcp [10694.783355] Key type .llcrypt unregistered [10694.785986] Key type ._llcrypt unregistered [10695.527176] alg: No test for adler32 (adler32-zlib) [10696.363438] Key type ._llcrypt registered [10696.373705] Key type .llcrypt registered [10696.618307] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10696.910825] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10697.089356] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10697.092290] LNet: Accept secure, port 988 [10698.799123] Key type lgssc registered [10700.030694] Lustre: Echo OBD driver; http://www.lustre.org/ [10711.272876] Lustre: DEBUG MARKER: Iteration 27 [10711.602083] LustreError: 352945:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10711.604375] LustreError: 352946:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10711.624118] LustreError: 352945:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [10712.635572] Lustre: Mounted lustre-client [10714.010027] Lustre: Unmounted lustre-client [10717.063257] Key type lgssc unregistered [10717.295548] LNet: 353299:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10718.371679] LNet: Removed LNI 192.168.204.57@tcp [10718.972971] Key type .llcrypt unregistered [10718.976284] Key type ._llcrypt unregistered [10719.791082] alg: No test for adler32 (adler32-zlib) [10720.616403] Key type ._llcrypt registered [10720.619046] Key type .llcrypt registered [10720.830910] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10721.204168] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10721.417228] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10721.422341] LNet: Accept secure, port 988 [10723.111181] Key type lgssc registered [10724.244975] Lustre: Echo OBD driver; http://www.lustre.org/ [10735.531142] Lustre: DEBUG MARKER: Iteration 28 [10735.748481] LustreError: 354089:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10735.754776] LustreError: 354097:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10735.766552] LustreError: 354089:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4992 [10736.765356] Lustre: Mounted lustre-client [10736.775601] Lustre: Skipped 1 previous similar message [10738.098987] Lustre: Unmounted lustre-client [10740.916389] Key type lgssc unregistered [10741.110715] LNet: 354443:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10742.177054] LNet: Removed LNI 192.168.204.57@tcp [10742.749940] Key type .llcrypt unregistered [10742.751984] Key type ._llcrypt unregistered [10743.374783] alg: No test for adler32 (adler32-zlib) [10744.131462] Key type ._llcrypt registered [10744.133497] Key type .llcrypt registered [10744.285730] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10744.530532] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10744.685328] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10744.688636] LNet: Accept secure, port 988 [10746.319077] Key type lgssc registered [10747.422315] Lustre: Echo OBD driver; http://www.lustre.org/ [10758.711736] Lustre: DEBUG MARKER: Iteration 29 [10758.992269] LustreError: 355238:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10758.992906] LustreError: 355239:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10759.015299] LustreError: 355238:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [10760.000187] Lustre: Mounted lustre-client [10761.525666] Lustre: Unmounted lustre-client [10763.788817] Key type lgssc unregistered [10763.985486] LNet: 355591:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10765.027167] LNet: Removed LNI 192.168.204.57@tcp [10765.551437] Key type .llcrypt unregistered [10765.557623] Key type ._llcrypt unregistered [10766.075274] alg: No test for adler32 (adler32-zlib) [10766.834513] Key type ._llcrypt registered [10766.837648] Key type .llcrypt registered [10767.024305] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10767.277639] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10767.507109] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10767.511904] LNet: Accept secure, port 988 [10769.199083] Key type lgssc registered [10770.321623] Lustre: Echo OBD driver; http://www.lustre.org/ [10779.619202] Lustre: DEBUG MARKER: Iteration 30 [10779.893077] LustreError: 356383:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10779.895433] LustreError: 356384:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10779.909222] LustreError: 356383:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4996 [10780.938884] Lustre: Mounted lustre-client [10782.269819] Lustre: Unmounted lustre-client [10785.166756] Key type lgssc unregistered [10785.415725] LNet: 356731:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10786.467942] LNet: Removed LNI 192.168.204.57@tcp [10787.095872] Key type .llcrypt unregistered [10787.098664] Key type ._llcrypt unregistered [10788.099716] alg: No test for adler32 (adler32-zlib) [10788.865455] Key type ._llcrypt registered [10788.868818] Key type .llcrypt registered [10789.070358] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10789.448387] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10789.667957] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10789.672388] LNet: Accept secure, port 988 [10791.359170] Key type lgssc registered [10792.379790] Lustre: Echo OBD driver; http://www.lustre.org/ [10803.177026] Lustre: DEBUG MARKER: Iteration 31 [10803.484705] LustreError: 357526:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10803.490140] LustreError: 357527:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10803.508100] LustreError: 357526:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4983 [10804.457548] Lustre: Mounted lustre-client [10806.113432] Lustre: Unmounted lustre-client [10808.623262] Key type lgssc unregistered [10808.867961] LNet: 357875:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10809.892188] LNet: Removed LNI 192.168.204.57@tcp [10810.683750] Key type .llcrypt unregistered [10810.686708] Key type ._llcrypt unregistered [10811.573158] alg: No test for adler32 (adler32-zlib) [10812.354189] Key type ._llcrypt registered [10812.359803] Key type .llcrypt registered [10812.610865] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10812.936482] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10813.272966] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10813.285419] LNet: Accept secure, port 988 [10815.058358] Key type lgssc registered [10816.468674] Lustre: Echo OBD driver; http://www.lustre.org/ [10829.060236] Lustre: DEBUG MARKER: Iteration 32 [10829.363755] LustreError: 358671:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10829.367633] LustreError: 358668:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10829.379590] LustreError: 358671:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4990 [10830.468484] Lustre: Mounted lustre-client [10830.475127] Lustre: Skipped 1 previous similar message [10832.332148] Lustre: Unmounted lustre-client [10835.024617] Key type lgssc unregistered [10835.274776] LNet: 359021:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10836.327457] LNet: Removed LNI 192.168.204.57@tcp [10837.070077] Key type .llcrypt unregistered [10837.072146] Key type ._llcrypt unregistered [10837.973704] alg: No test for adler32 (adler32-zlib) [10838.752726] Key type ._llcrypt registered [10838.757188] Key type .llcrypt registered [10838.975399] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10839.246339] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10839.497302] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10839.504516] LNet: Accept secure, port 988 [10841.247130] Key type lgssc registered [10842.512457] Lustre: Echo OBD driver; http://www.lustre.org/ [10854.134090] Lustre: DEBUG MARKER: Iteration 33 [10854.539564] LustreError: 359832:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10854.540787] LustreError: 359831:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10854.553944] LustreError: 359832:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=5000 [10855.623143] Lustre: Mounted lustre-client [10855.632612] Lustre: Skipped 1 previous similar message [10857.452045] Lustre: Unmounted lustre-client [10860.361240] Key type lgssc unregistered [10860.669645] LNet: 360185:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10861.732437] LNet: Removed LNI 192.168.204.57@tcp [10862.304633] Key type .llcrypt unregistered [10862.307580] Key type ._llcrypt unregistered [10863.144446] alg: No test for adler32 (adler32-zlib) [10863.906444] Key type ._llcrypt registered [10863.912696] Key type .llcrypt registered [10864.106125] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10864.360839] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10864.522677] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10864.528743] LNet: Accept secure, port 988 [10866.199314] Key type lgssc registered [10867.330306] Lustre: Echo OBD driver; http://www.lustre.org/ [10877.510758] Lustre: DEBUG MARKER: Iteration 34 [10877.809243] LustreError: 360980:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10877.816066] LustreError: 360978:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10877.831101] LustreError: 360980:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [10878.865298] Lustre: Mounted lustre-client [10880.447464] Lustre: Unmounted lustre-client [10882.646595] Key type lgssc unregistered [10882.960839] LNet: 361333:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10884.003445] LNet: Removed LNI 192.168.204.57@tcp [10884.546779] Key type .llcrypt unregistered [10884.548993] Key type ._llcrypt unregistered [10885.061658] alg: No test for adler32 (adler32-zlib) [10885.832111] Key type ._llcrypt registered [10885.836613] Key type .llcrypt registered [10886.076936] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10886.347128] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10886.589694] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10886.592789] LNet: Accept secure, port 988 [10888.225417] Key type lgssc registered [10889.363751] Lustre: Echo OBD driver; http://www.lustre.org/ [10900.728137] Lustre: DEBUG MARKER: Iteration 35 [10901.276975] LustreError: 362129:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10901.277598] LustreError: 362130:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10901.299588] LustreError: 362129:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4984 [10902.377158] Lustre: Mounted lustre-client [10904.166287] Lustre: Unmounted lustre-client [10907.226490] Key type lgssc unregistered [10907.550429] LNet: 362482:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10908.577575] LNet: Removed LNI 192.168.204.57@tcp [10909.355605] Key type .llcrypt unregistered [10909.357789] Key type ._llcrypt unregistered [10910.335268] alg: No test for adler32 (adler32-zlib) [10911.118919] Key type ._llcrypt registered [10911.124381] Key type .llcrypt registered [10911.484638] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10911.887475] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10912.142044] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10912.151425] LNet: Accept secure, port 988 [10913.903151] Key type lgssc registered [10915.396908] Lustre: Echo OBD driver; http://www.lustre.org/ [10926.656216] Lustre: DEBUG MARKER: Iteration 36 [10927.006397] LustreError: 363278:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10927.008103] LustreError: 363277:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10927.036126] LustreError: 363278:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [10928.094758] Lustre: Mounted lustre-client [10929.938282] Lustre: Unmounted lustre-client [10932.742554] Key type lgssc unregistered [10933.023575] LNet: 363630:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10934.051885] LNet: Removed LNI 192.168.204.57@tcp [10934.831245] Key type .llcrypt unregistered [10934.835365] Key type ._llcrypt unregistered [10935.572186] alg: No test for adler32 (adler32-zlib) [10936.356588] Key type ._llcrypt registered [10936.363477] Key type .llcrypt registered [10936.587313] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10936.852752] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10937.146896] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10937.159149] LNet: Accept secure, port 988 [10938.895165] Key type lgssc registered [10940.471276] Lustre: Echo OBD driver; http://www.lustre.org/ [10951.748696] Lustre: DEBUG MARKER: Iteration 37 [10952.018526] LustreError: 364419:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10952.019051] LustreError: 364424:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10952.037070] LustreError: 364419:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4985 [10953.097103] Lustre: Mounted lustre-client [10954.575361] Lustre: Unmounted lustre-client [10957.420384] Key type lgssc unregistered [10957.726250] LNet: 364778:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10958.752390] LNet: Removed LNI 192.168.204.57@tcp [10959.502556] Key type .llcrypt unregistered [10959.505428] Key type ._llcrypt unregistered [10960.576716] alg: No test for adler32 (adler32-zlib) [10961.334442] Key type ._llcrypt registered [10961.339435] Key type .llcrypt registered [10961.611531] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10961.988579] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10962.208660] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10962.216389] LNet: Accept secure, port 988 [10963.999143] Key type lgssc registered [10965.205299] Lustre: Echo OBD driver; http://www.lustre.org/ [10977.590878] Lustre: DEBUG MARKER: Iteration 38 [10978.030047] LustreError: 365572:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [10978.037891] LustreError: 365573:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [10978.074090] LustreError: 365572:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4967 [10979.166533] Lustre: Mounted lustre-client [10979.175459] Lustre: Skipped 1 previous similar message [10981.000411] Lustre: Unmounted lustre-client [10983.762812] Key type lgssc unregistered [10983.971408] LNet: 365921:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [10984.993309] LNet: Removed LNI 192.168.204.57@tcp [10985.652742] Key type .llcrypt unregistered [10985.661068] Key type ._llcrypt unregistered [10986.371379] alg: No test for adler32 (adler32-zlib) [10987.135592] Key type ._llcrypt registered [10987.138340] Key type .llcrypt registered [10987.362421] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [10987.647963] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [10987.859753] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [10987.866058] LNet: Accept secure, port 988 [10989.543123] Key type lgssc registered [10990.799114] Lustre: Echo OBD driver; http://www.lustre.org/ [11002.917595] Lustre: DEBUG MARKER: Iteration 39 [11003.244345] LustreError: 366711:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11003.244581] LustreError: 366715:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11003.279975] LustreError: 366711:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [11004.341304] Lustre: Mounted lustre-client [11006.000764] Lustre: Unmounted lustre-client [11006.003104] Lustre: Skipped 1 previous similar message [11008.708428] Key type lgssc unregistered [11008.993824] LNet: 367063:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11010.030924] LNet: Removed LNI 192.168.204.57@tcp [11010.735840] Key type .llcrypt unregistered [11010.739518] Key type ._llcrypt unregistered [11011.518333] alg: No test for adler32 (adler32-zlib) [11012.288493] Key type ._llcrypt registered [11012.290884] Key type .llcrypt registered [11012.531996] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11012.810284] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11013.058715] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11013.064610] LNet: Accept secure, port 988 [11014.775963] Key type lgssc registered [11015.856055] Lustre: Echo OBD driver; http://www.lustre.org/ [11026.649195] Lustre: DEBUG MARKER: Iteration 40 [11027.089835] LustreError: 367857:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11027.090053] LustreError: 367858:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11027.102747] LustreError: 367857:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=5000 [11028.085902] Lustre: Mounted lustre-client [11029.576405] Lustre: Unmounted lustre-client [11032.169868] Key type lgssc unregistered [11032.473463] LNet: 368208:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11033.505346] LNet: Removed LNI 192.168.204.57@tcp [11034.332632] Key type .llcrypt unregistered [11034.338924] Key type ._llcrypt unregistered [11035.249797] alg: No test for adler32 (adler32-zlib) [11036.027918] Key type ._llcrypt registered [11036.039039] Key type .llcrypt registered [11036.370864] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11036.901201] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11037.232220] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11037.238501] LNet: Accept secure, port 988 [11038.999129] Key type lgssc registered [11040.462517] Lustre: Echo OBD driver; http://www.lustre.org/ [11053.170897] Lustre: DEBUG MARKER: Iteration 41 [11053.607028] LustreError: 369002:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11053.607062] LustreError: 369003:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11053.625465] LustreError: 369002:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [11054.707264] Lustre: Mounted lustre-client [11054.718076] Lustre: Skipped 1 previous similar message [11056.491802] Lustre: Unmounted lustre-client [11059.581862] Key type lgssc unregistered [11059.949260] LNet: 369349:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11061.044731] LNet: Removed LNI 192.168.204.57@tcp [11061.958508] Key type .llcrypt unregistered [11061.961465] Key type ._llcrypt unregistered [11062.969110] alg: No test for adler32 (adler32-zlib) [11063.739684] Key type ._llcrypt registered [11063.743819] Key type .llcrypt registered [11064.066976] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11064.532884] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11064.892379] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11064.897891] LNet: Accept secure, port 988 [11066.705780] Key type lgssc registered [11068.626504] Lustre: Echo OBD driver; http://www.lustre.org/ [11083.162885] Lustre: DEBUG MARKER: Iteration 42 [11083.617977] LustreError: 370145:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11083.618636] LustreError: 370144:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11083.630661] LustreError: 370145:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4993 [11084.769376] Lustre: Mounted lustre-client [11086.475411] Lustre: Unmounted lustre-client [11090.009510] Key type lgssc unregistered [11090.288050] LNet: 370495:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11091.365831] LNet: Removed LNI 192.168.204.57@tcp [11092.210064] Key type .llcrypt unregistered [11092.221921] Key type ._llcrypt unregistered [11093.566322] alg: No test for adler32 (adler32-zlib) [11094.351001] Key type ._llcrypt registered [11094.359752] Key type .llcrypt registered [11094.756797] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11095.162705] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11095.456162] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11095.462827] LNet: Accept secure, port 988 [11097.279137] Key type lgssc registered [11098.638415] Lustre: Echo OBD driver; http://www.lustre.org/ [11111.791377] Lustre: DEBUG MARKER: Iteration 43 [11112.398805] LustreError: 371291:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11112.400210] LustreError: 371292:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11112.427136] LustreError: 371291:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [11113.562205] Lustre: Mounted lustre-client [11115.574675] Lustre: Unmounted lustre-client [11118.415346] Key type lgssc unregistered [11118.687960] LNet: 371642:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11119.783653] LNet: Removed LNI 192.168.204.57@tcp [11120.583919] Key type .llcrypt unregistered [11120.586655] Key type ._llcrypt unregistered [11121.335715] alg: No test for adler32 (adler32-zlib) [11122.123724] Key type ._llcrypt registered [11122.127121] Key type .llcrypt registered [11122.342047] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11122.701843] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11122.984867] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11122.989925] LNet: Accept secure, port 988 [11124.679916] Key type lgssc registered [11125.708412] Lustre: Echo OBD driver; http://www.lustre.org/ [11138.583520] Lustre: DEBUG MARKER: Iteration 44 [11138.903182] LustreError: 372437:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11138.910039] LustreError: 372438:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11138.925281] LustreError: 372437:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4989 [11140.037946] Lustre: Mounted lustre-client [11141.784501] Lustre: Unmounted lustre-client [11145.079914] Key type lgssc unregistered [11145.387279] LNet: 372790:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11146.404688] LNet: Removed LNI 192.168.204.57@tcp [11147.448054] Key type .llcrypt unregistered [11147.455244] Key type ._llcrypt unregistered [11148.591722] alg: No test for adler32 (adler32-zlib) [11149.347461] Key type ._llcrypt registered [11149.349750] Key type .llcrypt registered [11149.605356] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11149.992798] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11150.166172] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11150.172892] LNet: Accept secure, port 988 [11151.863158] Key type lgssc registered [11152.863287] Lustre: Echo OBD driver; http://www.lustre.org/ [11165.066858] Lustre: DEBUG MARKER: Iteration 45 [11165.417462] LustreError: 373585:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11165.429103] LustreError: 373586:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11165.432921] LustreError: 373585:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4991 [11166.511748] Lustre: Mounted lustre-client [11168.303226] Lustre: Unmounted lustre-client [11172.427381] Key type lgssc unregistered [11172.753742] LNet: 373936:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11173.791969] LNet: Removed LNI 192.168.204.57@tcp [11174.536156] Key type .llcrypt unregistered [11174.539082] Key type ._llcrypt unregistered [11175.669399] alg: No test for adler32 (adler32-zlib) [11176.482400] Key type ._llcrypt registered [11176.487758] Key type .llcrypt registered [11176.806333] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11177.244438] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11177.701409] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11177.716825] LNet: Accept secure, port 988 [11179.507679] Key type lgssc registered [11181.114836] Lustre: Echo OBD driver; http://www.lustre.org/ [11194.834671] Lustre: DEBUG MARKER: Iteration 46 [11195.298216] LustreError: 374731:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11195.298800] LustreError: 374732:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11195.317417] LustreError: 374731:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4988 [11196.348436] Lustre: Mounted lustre-client [11198.508222] Lustre: Unmounted lustre-client [11201.443878] Key type lgssc unregistered [11201.685120] LNet: 375077:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11202.735907] LNet: Removed LNI 192.168.204.57@tcp [11203.578679] Key type .llcrypt unregistered [11203.581182] Key type ._llcrypt unregistered [11204.434742] alg: No test for adler32 (adler32-zlib) [11205.221357] Key type ._llcrypt registered [11205.223577] Key type .llcrypt registered [11205.574548] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11205.991478] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11206.305832] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11206.312854] LNet: Accept secure, port 988 [11208.015195] Key type lgssc registered [11209.284223] Lustre: Echo OBD driver; http://www.lustre.org/ [11222.740265] Lustre: DEBUG MARKER: Iteration 47 [11223.168494] LustreError: 375873:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11223.168746] LustreError: 375874:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11223.196257] LustreError: 375873:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4980 [11224.276887] Lustre: Mounted lustre-client [11225.633196] Lustre: Unmounted lustre-client [11229.050161] Key type lgssc unregistered [11229.370696] LNet: 376225:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11230.436790] LNet: Removed LNI 192.168.204.57@tcp [11231.248461] Key type .llcrypt unregistered [11231.251382] Key type ._llcrypt unregistered [11232.359175] alg: No test for adler32 (adler32-zlib) [11233.223152] Key type ._llcrypt registered [11233.227843] Key type .llcrypt registered [11233.435871] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11233.761379] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11234.030363] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11234.050540] LNet: Accept secure, port 988 [11235.752262] Key type lgssc registered [11237.321281] Lustre: Echo OBD driver; http://www.lustre.org/ [11250.863258] Lustre: DEBUG MARKER: Iteration 48 [11251.417514] LustreError: 377021:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11251.427332] LustreError: 377022:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11251.441059] LustreError: 377021:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4987 [11252.577663] Lustre: Mounted lustre-client [11254.473130] Lustre: Unmounted lustre-client [11257.673102] Key type lgssc unregistered [11258.035048] LNet: 377375:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11259.106524] LNet: Removed LNI 192.168.204.57@tcp [11259.821850] Key type .llcrypt unregistered [11259.824845] Key type ._llcrypt unregistered [11260.662106] alg: No test for adler32 (adler32-zlib) [11261.445257] Key type ._llcrypt registered [11261.455933] Key type .llcrypt registered [11261.751258] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11262.094506] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11262.280895] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11262.284892] LNet: Accept secure, port 988 [11263.991155] Key type lgssc registered [11265.409490] Lustre: Echo OBD driver; http://www.lustre.org/ [11280.076336] Lustre: DEBUG MARKER: Iteration 49 [11280.460479] LustreError: 378167:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11280.461932] LustreError: 378169:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11280.488501] LustreError: 378167:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4986 [11281.570184] Lustre: Mounted lustre-client [11283.734874] Lustre: Unmounted lustre-client [11287.177416] Key type lgssc unregistered [11287.518742] LNet: 378520:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11288.546930] LNet: Removed LNI 192.168.204.57@tcp [11289.573221] Key type .llcrypt unregistered [11289.577650] Key type ._llcrypt unregistered [11290.508942] alg: No test for adler32 (adler32-zlib) [11291.265662] Key type ._llcrypt registered [11291.267619] Key type .llcrypt registered [11291.422914] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11291.722212] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11291.915919] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11291.920832] LNet: Accept secure, port 988 [11293.599203] Key type lgssc registered [11294.766888] Lustre: Echo OBD driver; http://www.lustre.org/ [11305.578303] Lustre: DEBUG MARKER: Iteration 50 [11305.937624] LustreError: 379311:0:(libcfs_fail.h:169:cfs_race()) cfs_race id 1417 sleeping [11305.939309] LustreError: 379325:0:(libcfs_fail.h:180:cfs_race()) cfs_fail_race id 1417 waking [11305.962951] LustreError: 379311:0:(libcfs_fail.h:178:cfs_race()) cfs_fail_race id 1417 awake: rc=4977 [11307.066161] Lustre: Mounted lustre-client [11307.078305] Lustre: Skipped 1 previous similar message [11308.488570] Lustre: Unmounted lustre-client [11311.195670] Key type lgssc unregistered [11311.523627] LNet: 379663:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11312.544939] LNet: Removed LNI 192.168.204.57@tcp [11313.151541] Key type .llcrypt unregistered [11313.153674] Key type ._llcrypt unregistered [11314.407683] alg: No test for adler32 (adler32-zlib) [11315.167313] Key type ._llcrypt registered [11315.171584] Key type .llcrypt registered [11315.462476] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [11315.769799] Lustre: Lustre: Build Version: 2.15.8_2_g7406dad [11315.939797] LNet: Added LNI 192.168.204.57@tcp [8/256/0/180] [11315.948379] LNet: Accept secure, port 988 [11317.639151] Key type lgssc registered [11318.986964] Lustre: Echo OBD driver; http://www.lustre.org/ [11330.547262] Lustre: Mounted lustre-client [11337.977896] Lustre: DEBUG MARKER: == sanityn test 110: do not grant another lock on resend ========================================================== 15:15:19 (1781291719) [11347.423220] Lustre: 380971:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1781291723/real 1781291723] req@00000000d36c0ddb x1867819724576512/t0(0) o36->lustre-MDT0000-mdc-ffff9d0f88398800@192.168.204.157@tcp:12/10 lens 496/440 e 0 to 1 dl 1781291730 ref 2 fl Rpc:XQr/0/ffffffff rc 0/-1 job:'ln.0' [11347.466602] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection to lustre-MDT0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [11347.569274] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection restored to (at 192.168.204.157@tcp) [11354.085171] Lustre: 380971:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1781291730/real 1781291730] req@00000000d36c0ddb x1867819724576512/t0(0) o36->lustre-MDT0000-mdc-ffff9d0f88398800@192.168.204.157@tcp:12/10 lens 496/440 e 0 to 1 dl 1781291737 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11354.137362] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection to lustre-MDT0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [11354.202816] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection restored to (at 192.168.204.157@tcp) [11361.247228] Lustre: 380971:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1781291737/real 1781291737] req@00000000d36c0ddb x1867819724576512/t0(0) o36->lustre-MDT0000-mdc-ffff9d0f88398800@192.168.204.157@tcp:12/10 lens 496/440 e 0 to 1 dl 1781291744 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11361.291836] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection to lustre-MDT0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [11361.325131] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection restored to (at 192.168.204.157@tcp) [11368.415454] Lustre: 380971:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1781291744/real 1781291744] req@00000000d36c0ddb x1867819724576512/t0(0) o36->lustre-MDT0000-mdc-ffff9d0f88398800@192.168.204.157@tcp:12/10 lens 496/440 e 0 to 1 dl 1781291751 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11368.479080] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection to lustre-MDT0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [11368.520412] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection restored to (at 192.168.204.157@tcp) [11375.587145] Lustre: 380971:0:(client.c:2295:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1781291751/real 1781291751] req@00000000d36c0ddb x1867819724576512/t0(0) o36->lustre-MDT0000-mdc-ffff9d0f88398800@192.168.204.157@tcp:12/10 lens 496/440 e 0 to 1 dl 1781291758 ref 2 fl Rpc:XQr/2/ffffffff rc 0/-1 job:'ln.0' [11375.636457] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection to lustre-MDT0000 (at 192.168.204.157@tcp) was lost; in progress operations using this service will wait for recovery to complete [11375.687443] Lustre: lustre-MDT0000-mdc-ffff9d0f88398800: Connection restored to (at 192.168.204.157@tcp) [11383.293879] Lustre: DEBUG MARKER: == sanityn test 111: A racy rename/link an open file should not cause fs corruption ========================================================== 15:16:05 (1781291765) [11395.275548] Lustre: DEBUG MARKER: == sanityn test 112: update max-inherit in default LMV === 15:16:17 (1781291777) [11410.405727] Lustre: DEBUG MARKER: == sanityn test 113: check servers of specified fs ======= 15:16:32 (1781291792) [11417.313980] Lustre: DEBUG MARKER: cleanup: ====================================================== [11419.297488] Lustre: DEBUG MARKER: == sanityn test complete, duration 11171 sec ============= 15:16:40 (1781291800) [11794.890185] Lustre: Unmounted lustre-client [11797.725205] Lustre: Unmounted lustre-client [11838.537239] Key type lgssc unregistered [11838.929907] LNet: 384140:0:(lib-ptl.c:992:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [11839.991559] LNet: Removed LNI 192.168.204.57@tcp [11840.806632] Key type .llcrypt unregistered [11840.808646] Key type ._llcrypt unregistered