[ 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-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 517153326 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2400.000 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 = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 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-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 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 0xbffce000-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: 1059606 [ 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: 2895240K/4306352K 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.001011] APIC: Switch to symmetric I/O mode setup [ 0.002489] x2apic enabled [ 0.003008] Switched APIC routing to physical x2apic. [ 0.004013] kvm-guest: setup PV IPIs [ 0.007538] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 0.008021] Calibrating delay loop (skipped) preset value.. 4800.00 BogoMIPS (lpj=2400000) [ 0.009012] pid_max: default: 32768 minimum: 301 [ 0.010131] LSM: Security Framework initializing [ 0.011056] Yama: becoming mindful. [ 0.012047] SELinux: Initializing. [ 0.013078] *** VALIDATE selinux *** [ 0.022350] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.027692] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.028149] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029105] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030117] *** VALIDATE tmpfs *** [ 0.031473] *** VALIDATE proc *** [ 0.032252] *** VALIDATE cgroup *** [ 0.033010] *** VALIDATE cgroup2 *** [ 0.035080] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.037076] 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.039029] Spectre V2 : User space: Vulnerable [ 0.040008] Speculative Store Bypass: Vulnerable [ 0.043562] debug: unmapping init [mem 0xffffffffa0e59000-0xffffffffa0e60fff] [ 0.045967] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.046688] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.048026] ... version: 2 [ 0.049014] ... bit width: 48 [ 0.050015] ... generic registers: 4 [ 0.051015] ... value mask: 0000ffffffffffff [ 0.052016] ... max period: 00007fffffffffff [ 0.053020] ... fixed-purpose events: 3 [ 0.054015] ... event mask: 000000070000000f [ 0.055312] rcu: Hierarchical SRCU implementation. [ 0.057644] smp: Bringing up secondary CPUs ... [ 0.058770] x86: Booting SMP configuration: [ 0.059031] .... node #0, CPUs: #1 #2 #3 [ 0.069265] smp: Brought up 1 node, 4 CPUs [ 0.071014] smpboot: Max logical packages: 1 [ 0.072020] smpboot: Total of 4 processors activated (19200.00 BogoMIPS) [ 0.152089] node 0 deferred pages initialised in 79ms [ 0.158334] devtmpfs: initialized [ 0.160231] x86/mm: Memory block size: 128MB [ 0.164230] gcov: version magic: 0x41383552 [ 0.170813] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.178137] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.184987] pinctrl core: initialized pinctrl subsystem [ 0.188270] [ 0.189009] ************************************************************* [ 0.193012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.197014] ** ** [ 0.201016] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.204011] ** ** [ 0.206012] ** This means that this kernel is built to expose internal ** [ 0.209014] ** IOMMU data structures, which may compromise security on ** [ 0.212011] ** your system. ** [ 0.214010] ** ** [ 0.216011] ** If you see this message and you are not debugging the ** [ 0.219010] ** kernel, report this immediately to your vendor! ** [ 0.221010] ** ** [ 0.223076] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.226016] ************************************************************* [ 0.230910] NET: Registered protocol family 16 [ 0.233566] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.237338] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.242064] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.252048] cpuidle: using governor menu [ 0.290175] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.293059] PCI: Using configuration type 1 for base access [ 0.296226] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.308224] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.312121] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.319071] cryptd: max_cpu_qlen set to 1000 [ 0.324347] ACPI: Added _OSI(Module Device) [ 0.328016] ACPI: Added _OSI(Processor Device) [ 0.331017] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.334020] ACPI: Added _OSI(Processor Aggregator Device) [ 0.347610] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.364000] ACPI: Interpreter enabled [ 0.367318] ACPI: PM: (supports S0 S3 S4 S5) [ 0.372014] ACPI: Using IOAPIC for interrupt routing [ 0.376128] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.384000] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.409927] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.416049] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.423019] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.430778] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.441732] acpiphp: Slot [2] registered [ 0.446042] acpiphp: Slot [5] registered [ 0.447154] acpiphp: Slot [6] registered [ 0.451369] acpiphp: Slot [7] registered [ 0.453150] acpiphp: Slot [8] registered [ 0.457158] acpiphp: Slot [9] registered [ 0.460942] acpiphp: Slot [10] registered [ 0.463144] acpiphp: Slot [3] registered [ 0.465130] acpiphp: Slot [4] registered [ 0.468038] acpiphp: Slot [11] registered [ 0.470125] acpiphp: Slot [12] registered [ 0.473141] acpiphp: Slot [13] registered [ 0.476129] acpiphp: Slot [14] registered [ 0.479130] acpiphp: Slot [15] registered [ 0.482359] acpiphp: Slot [16] registered [ 0.485151] acpiphp: Slot [17] registered [ 0.486484] acpiphp: Slot [18] registered [ 0.489746] acpiphp: Slot [19] registered [ 0.493350] acpiphp: Slot [20] registered [ 0.495119] acpiphp: Slot [21] registered [ 0.498109] acpiphp: Slot [22] registered [ 0.500126] acpiphp: Slot [23] registered [ 0.502108] acpiphp: Slot [24] registered [ 0.505353] acpiphp: Slot [25] registered [ 0.508149] acpiphp: Slot [26] registered [ 0.509480] acpiphp: Slot [27] registered [ 0.513139] acpiphp: Slot [28] registered [ 0.515122] acpiphp: Slot [29] registered [ 0.518117] acpiphp: Slot [30] registered [ 0.519130] acpiphp: Slot [31] registered [ 0.522080] PCI host bridge to bus 0000:00 [ 0.524019] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.528023] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.531024] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.537024] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.539023] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.542026] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.544148] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.547173] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.551309] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.562015] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.567056] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.570020] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.571017] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.574019] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.577372] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.579885] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.583106] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.585653] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.590014] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.604014] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.608922] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.616087] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.627016] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.635016] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.652016] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.656000] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.656000] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.706053] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.744034] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.756140] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.764021] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.780052] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.805027] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.819495] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.825015] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.832118] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.846016] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.854274] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.857015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.858000] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.866021] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.872000] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.872000] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.878018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.893057] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.904931] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.907553] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.910457] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.912584] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.914217] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.918052] iommu: Default domain type: Passthrough [ 0.919000] SCSI subsystem initialized [ 0.919000] ACPI: bus type USB registered [ 0.919000] usbcore: registered new interface driver usbfs [ 0.919000] usbcore: registered new interface driver hub [ 0.919000] usbcore: registered new device driver usb [ 0.919000] pps_core: LinuxPPS API ver. 1 registered [ 0.958014] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.966067] PTP clock support registered [ 0.972149] EDAC MC: Ver: 3.0.0 [ 1.124105] PCI: Using ACPI for IRQ routing [ 1.126407] NetLabel: Initializing [ 1.128014] NetLabel: domain hash size = 128 [ 1.130012] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 1.132136] NetLabel: unlabeled traffic allowed by default [ 1.134322] vgaarb: loaded [ 1.135646] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.137008] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.144384] clocksource: Switched to clocksource kvm-clock [ 1.273586] VFS: Disk quotas dquot_6.6.0 [ 1.275123] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.277343] *** VALIDATE ramfs *** [ 1.278524] *** VALIDATE hugetlbfs *** [ 1.279855] pnp: PnP ACPI init [ 1.282332] pnp: PnP ACPI: found 6 devices [ 1.300721] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.304152] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.307027] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.309119] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.311092] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.313169] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.315747] NET: Registered protocol family 2 [ 1.317935] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.322749] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.326170] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.331946] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.335906] TCP: Hash tables configured (established 65536 bind 65536) [ 1.338601] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.341919] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.345181] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.348026] NET: Registered protocol family 1 [ 1.351273] RPC: Registered named UNIX socket transport module. [ 1.353864] RPC: Registered udp transport module. [ 1.360867] RPC: Registered tcp transport module. [ 1.365544] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.372305] NET: Registered protocol family 44 [ 1.376878] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.381198] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.385783] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.415304] pci 0000:00:01.0: quirk_isa_dma_hangs+0x0/0x20 took 28828 usecs [ 1.491051] PCI: CLS 0 bytes, default 64 [ 1.496265] Unpacking initramfs... [ 4.640590] debug: unmapping init [mem 0xffff9d20bcc54000-0xffff9d20bffbffff] [ 4.645305] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 4.647857] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 4.651054] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x22983777dd9, max_idle_ns: 440795300422 ns [ 5.294382] Initialise system trusted keyrings [ 5.297060] Key type blacklist registered [ 5.298408] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 5.308130] zbud: loaded [ 5.311050] *** VALIDATE nfs *** [ 5.311989] *** VALIDATE nfs4 *** [ 5.313482] pstore: using deflate compression [ 5.317137] Platform Keyring initialized [ 5.491514] NET: Registered protocol family 38 [ 5.496941] Key type asymmetric registered [ 5.500905] Asymmetric key parser 'x509' registered [ 5.505541] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 5.515846] io scheduler mq-deadline registered [ 5.524033] io scheduler kyber registered [ 5.529870] io scheduler bfq registered [ 5.538441] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 5.545732] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 5.551994] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 5.555412] ACPI: Power Button [PWRF] [ 5.567227] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 5.579080] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 5.626122] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 5.634134] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 5.649173] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 5.678529] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 5.708126] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 5.713981] Non-volatile memory driver v1.3 [ 5.716430] Linux agpgart interface v0.103 [ 5.749501] virtio_blk virtio1: [vda] 133608 512-byte logical blocks (68.4 MB/65.2 MiB) [ 5.754701] vda: detected capacity change from 0 to 68407296 [ 5.842173] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 5.847251] vdb: detected capacity change from 0 to 1073741824 [ 5.930409] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 5.935045] vdc: detected capacity change from 0 to 2621440000 [ 5.952140] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 5.955487] vdd: detected capacity change from 0 to 2621440000 [ 5.970760] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 5.973631] vde: detected capacity change from 0 to 4294967296 [ 5.989484] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 5.992501] vdf: detected capacity change from 0 to 4294967296 [ 5.999528] libphy: Fixed MDIO Bus: probed [ 6.019976] usbcore: registered new interface driver usbserial_generic [ 6.023173] usbserial: USB Serial support registered for generic [ 6.026134] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 6.031810] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 6.033833] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 6.036871] mousedev: PS/2 mouse device common for all mice [ 6.039783] rtc_cmos 00:05: RTC can wake from S4 [ 6.044606] rtc_cmos 00:05: registered as rtc0 [ 6.046019] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 6.049181] intel_pstate: CPU model not supported [ 6.052521] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 6.057835] hid: raw HID events driver (C) Jiri Kosina [ 6.060043] usbcore: registered new interface driver usbhid [ 6.061861] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 6.065965] usbhid: USB HID core driver [ 6.066212] drop_monitor: Initializing network drop monitor service [ 6.066358] Initializing XFRM netlink socket [ 6.067833] NET: Registered protocol family 10 [ 6.074667] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 6.078402] Segment Routing with IPv6 [ 6.086868] NET: Registered protocol family 17 [ 6.088972] mpls_gso: MPLS GSO support [ 6.093915] RAS: Correctable Errors collector initialized. [ 6.096185] AVX version of gcm_enc/dec engaged. [ 6.097875] AES CTR mode by8 optimization enabled [ 6.364801] sched_clock: Marking stable (6364759914, 0)->(7887655368, -1522895454) [ 6.659617] registered taskstats version 1 [ 6.869779] Loading compiled-in X.509 certificates [ 6.872487] zswap: loaded using pool lzo/zbud [ 6.903646] Key type big_key registered [ 7.154674] Key type encrypted registered [ 7.157420] ima: No TPM chip found, activating TPM-bypass! [ 7.159787] ima: Allocated hash algorithm: sha1 [ 7.161474] ima: No architecture policies found [ 7.164635] evm: Initialising EVM extended attributes: [ 7.167148] evm: security.selinux [ 7.168259] evm: security.ima [ 7.169355] evm: security.capability [ 7.171298] evm: HMAC attrs: 0x1 [ 7.175719] rtc_cmos 00:05: setting system clock to 2026-03-11 13:14:25 UTC (1773234865) [ 7.191119] debug: unmapping init [mem 0xffffffffa1e03000-0xffffffffa1ffffff] [ 7.435816] debug: unmapping init [mem 0xffffffffa0b82000-0xffffffffa0e58fff] [ 7.459975] Write protecting the kernel read-only data: 28672k [ 7.475348] debug: unmapping init [mem 0xffffffff9f203000-0xffffffff9f3fffff] [ 7.485601] debug: unmapping init [mem 0xffffffff9fb14000-0xffffffff9fbfffff] [ 7.549086] 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) [ 7.559652] systemd[1]: Detected virtualization kvm. [ 7.562727] systemd[1]: Detected architecture x86-64. [ 7.567628] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 7.612820] systemd[1]: No hostname configured. [ 7.617689] systemd[1]: Set hostname to . [ 7.623798] random: systemd: uninitialized urandom read (16 bytes read) [ 7.639891] systemd[1]: Initializing machine ID from random generator. [ 8.358629] random: systemd: uninitialized urandom read (16 bytes read) [ 8.365218] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 8.378881] random: systemd: uninitialized urandom read (16 bytes read) [ 8.382348] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 8.396879] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... Starting Create list of required st…ce nodes for the current kernel... Starting Journal Service... [ OK ] Reached target Timers. [ OK ] Listening on udev Control Socket. [ OK ] Started Memstrack Anylazing Service. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Local File Systems. Starting Apply Kernel Variables... [ OK ] Reached target Slices. [ OK ] Reached target Initrd Root Device. Starting Create Volatile Files and Directories... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Sockets. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 10.351785] device-mapper: uevent: version 1.0.3 [ 10.353804] 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... [ 12.404917] virtio_net virtio0 ens2: renamed from eth0 [ 12.815179] random: fast init done [ 13.152258] scsi host0: ata_piix [ 13.273521] scsi host1: ata_piix [ 13.286469] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 13.307531] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 18.738521] random: crng init done [ 18.740130] random: 7 urandom warning(s) missed due to ratelimiting [ 22.733624] dracut-initqueue[598]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 24.972430] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Timers. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target System Initialization. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 28.671347] printk: systemd: 26 output lines suppressed due to ratelimiting [ 29.587847] SELinux: Disabled at runtime. [ 29.718364] 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) [ 29.745787] systemd[1]: Detected virtualization kvm. [ 29.757646] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 32.540097] systemd[1]: initrd-switch-root.service: Succeeded. [ 32.554848] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 32.596811] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 32.611126] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 32.619464] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 32.660526] systemd[1]: Starting Journal Service... Starting Journal Service... [ 32.707799] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. Starting Create list of required st…ce nodes for the current kernel... Mounting Huge Pages File System... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on initctl Compatibility Named Pipe. Starting Remount Root and Kernel File Systems... [ OK ] Reached target rpc_pipefs.target. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Activating swap /dev/disk/by-label/SWAP... [ OK ] Stopped target Initrd Root File System. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Mounting POSIX Message Queue File System... [ OK ] Created slice system-getty.slice. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK [ 33.369087] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS ] Reached target Paths. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Process Core Dump Socket. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. Mounting Kernel Debug File System... Starting Apply Kernel Variables... [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Mounted Kernel Debug File System. [ OK ] Started Apply Kernel Variables. [ 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 udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ 35.213101] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ 35.633903] hrtimer: interrupt took 3068737 ns [ OK ] Started udev Kernel Device Manager. [ 36.808778] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 36.893039] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 37.578598] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 37.708852] EDAC sbridge: Ver: 1.1.2 [* ] A start job is running for Configur…-only root support (9s / no limit) [** ] A start job is running for Configur…-only root support (9s / no limit) [*** ] A start job is running for Configur…only root support (10s / no limit) [ *** ] A start job is running for Configur…only root support (11s / no limit)[ 44.180608] Key type dns_resolver registered [ *** ] A start job is running for Configur…only root support (11s / no limit) [ ***] A start job is running for Configur…only root support (12s / no limit)[ 45.264062] NFS: Registering the id_resolver key type [ 45.267194] Key type id_resolver registered [ 45.269513] Key type id_legacy registered [ **] A start job is running for Configur…only root support (13s / no limit) [ *] A start job is running for Configur…only root support (13s / no limit) [ OK ] Started Configure read-only root support. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Mark the need to relabel after reboot. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. [ OK ] Started irqbalance daemon. Starting Login Service... Starting Restore /run/initramfs on shutdown... Starting Network Manager... [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Dynamic System Tuning Daemon... Starting Network Manager Wait Online... [ 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... Starting Hostname Service... [ OK ] Started Login Service. [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Notify NFS peers of a restart... Starting System Logging Service... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg438-server login: [ 93.466353] libcfs: loading out-of-tree module taints kernel. [ 93.517626] Key type ._llcrypt registered [ 93.520619] Key type .llcrypt registered [ 93.601774] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 107.861821] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 109.377412] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 109.392805] alg: No test for adler32 (adler32-zlib) [ 110.782629] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 111.503935] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 113.223162] Key type lgssc registered [ 114.458845] Lustre: Echo OBD driver; http://www.lustre.org/ [ 127.362373] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 128.449411] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 133.071692] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 138.205305] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 147.465511] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 156.873242] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 156.911991] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 156.928649] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 158.116255] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 158.145842] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 158.216575] Lustre: lustre-MDT0000: new disk, initializing [ 158.262641] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 158.277083] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 160.699941] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 163.900355] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 168.915403] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 168.960078] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 169.110885] Lustre: lustre-OST0000: new disk, initializing [ 169.113805] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 169.116547] Lustre: Skipped 1 previous similar message [ 169.134304] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 172.205291] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 172.701648] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 172.713320] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 172.749455] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 181.718463] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 181.780370] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 181.857825] Lustre: lustre-OST0001: new disk, initializing [ 181.861448] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 181.898314] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 185.383362] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 192.055342] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 192.066889] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 192.093901] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 194.726092] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 199.690582] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 208.656472] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing check_logdir /tmp/testlogs/ [ 211.919331] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing yml_node [ 214.454471] Lustre: DEBUG MARKER: Client: 2.16.59.50 [ 216.085289] Lustre: DEBUG MARKER: MDS: 2.16.59.50 [ 217.472407] Lustre: DEBUG MARKER: OSS: 2.16.59.50 [ 218.402932] Lustre: DEBUG MARKER: -----============= acceptance-small: conf-sanity ============----- Wed Mar 11 09:17:55 EDT 2026 [ 228.178970] Lustre: DEBUG MARKER: excepting tests: 32newtarball [ 228.978790] Lustre: DEBUG MARKER: skipping tests SLOW=no: 45 69 106 111 114 [ 243.167679] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 243.168337] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 243.176325] Lustre: Skipped 1 previous similar message [ 248.198642] LustreError: 10713:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 248.280747] Lustre: server umount lustre-MDT0000 complete [ 250.339863] LustreError: 5940:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773235108 with bad export cookie 5184859703431384057 [ 250.341125] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 250.348475] LustreError: 5940:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 250.377112] LustreError: 10914:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 250.381400] LustreError: 10914:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 250.418807] Lustre: server umount lustre-OST0000 complete [ 252.667434] LustreError: 11115:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 252.671100] LustreError: 11115:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 252.737237] Lustre: server umount lustre-OST0001 complete [ 256.221488] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 260.817153] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 265.709536] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 268.890471] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 271.890209] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 275.680755] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 275.724838] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 275.872913] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 275.895350] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 275.940331] Lustre: lustre-MDT0000: new disk, initializing [ 275.985401] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 275.996315] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 278.058818] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 282.205771] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 286.100512] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 286.169500] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 286.396394] Lustre: lustre-OST0000: new disk, initializing [ 286.399435] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 286.405927] Lustre: Skipped 1 previous similar message [ 286.468079] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 287.789157] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 287.795458] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 287.818106] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 290.921452] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 296.387944] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 299.018168] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 299.191932] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 303.074846] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 303.078400] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 303.088115] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 303.093188] Lustre: Skipped 1 previous similar message [ 306.485133] LustreError: 14850:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 306.487876] LustreError: 14850:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 306.566731] Lustre: server umount lustre-OST0000 complete [ 308.853284] Lustre: server umount lustre-MDT0000 complete [ 312.414784] Lustre: DEBUG MARKER: == conf-sanity test 121: failover MGS ==================== 09:19:29 (1773235169) [ 322.357360] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 322.723236] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 325.158143] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 328.523651] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 329.889531] Lustre: Failing over lustre-MDT0000 [ 329.982328] LustreError: 16583:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 329.991611] LustreError: 16583:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 330.109098] Lustre: server umount lustre-MDT0000 complete [ 345.758856] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 346.120878] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 348.536805] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 353.514661] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mgc.*.mgs_server_uuid [ 356.243362] LustreError: 17584:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 356.249619] LustreError: 17584:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 356.374106] Lustre: server umount lustre-MDT0000 complete [ 362.375744] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 365.313810] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 368.432917] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 369.896070] Lustre: Failing over lustre-MDT0000 [ 370.119567] Lustre: server umount lustre-MDT0000 complete [ 384.933396] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 385.214497] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 385.218747] Lustre: Skipped 1 previous similar message [ 387.262589] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 392.388466] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mgc.*.mgs_server_uuid [ 395.123095] LustreError: 19606:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 395.125958] LustreError: 19606:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 395.235943] Lustre: server umount lustre-MDT0000 complete [ 400.366371] Lustre: DEBUG MARKER: == conf-sanity test 122a: Check OST sequence update ====== 09:20:57 (1773235257) [ 401.276903] Lustre: DEBUG MARKER: SKIP: conf-sanity test_122a needs >= 2 MDTs [ 402.351688] Lustre: DEBUG MARKER: == conf-sanity test 123aa: llog_print works with FIDs and simple names ========================================================== 09:20:59 (1773235259) [ 405.916635] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 408.393493] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 411.491434] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 414.908350] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 418.012185] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 420.622726] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 426.611619] Lustre: DEBUG MARKER: == conf-sanity test 123ab: llog_print params output values from set_param -P ========================================================== 09:21:24 (1773235284) [ 427.497768] Lustre: Modifying parameter general.jobid_name=TESTNAME in log params [ 431.639556] Lustre: DEBUG MARKER: == conf-sanity test 123ac: llog_print with --start and --end ========================================================== 09:21:29 (1773235289) [ 436.314255] Lustre: DEBUG MARKER: == conf-sanity test 123ad: llog_print shows all records == 09:21:33 (1773235293) [ 436.872471] Lustre: Setting parameter lustre-OST0000-osc.osc.max_dirty_mb=462 in log lustre-client [ 436.876281] Lustre: Skipped 1 previous similar message [ 443.023657] Lustre: DEBUG MARKER: == conf-sanity test 123ae: llog_cancel can cancel requested record ========================================================== 09:21:40 (1773235300) [ 455.855491] Lustre: Disabling parameter lustre-OST0000-osc.osc.max_pages_per_rpc= in log lustre-client [ 455.858622] Lustre: Skipped 9 previous similar messages [ 457.529952] Lustre: DEBUG MARKER: == conf-sanity test 123af: llog_catlist can show all config files correctly ========================================================== 09:21:54 (1773235314) [ 459.003241] Lustre: *** cfs_fail_loc=131b, val=2*** [ 461.007670] Lustre: *** cfs_fail_loc=131b, val=2*** [ 465.779516] Lustre: DEBUG MARKER: == conf-sanity test 123ag: llog_print skips values deleted by set_param -P -d ========================================================== 09:22:03 (1773235323) [ 474.227848] Lustre: DEBUG MARKER: == conf-sanity test 123ah: del_ost cancels config log entries correctly ========================================================== 09:22:11 (1773235331) [ 482.787600] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 482.795742] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 486.720106] LustreError: 26110:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 486.724959] LustreError: 26110:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 486.781736] Lustre: server umount lustre-OST0000 complete [ 489.126834] Lustre: server umount lustre-MDT0000 complete [ 494.607921] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 496.317667] Key type lgssc unregistered [ 496.502498] LNet: 26843:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 496.506026] LNetError: 26843:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 496.514689] LNet: Removed LNI 192.168.204.138@tcp [ 497.021228] Key type .llcrypt unregistered [ 497.024644] Key type ._llcrypt unregistered [ 505.691406] Key type ._llcrypt registered [ 505.693315] Key type .llcrypt registered [ 505.753103] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 513.732989] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 514.258321] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 514.277804] alg: No test for adler32 (adler32-zlib) [ 515.205267] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 515.320424] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 516.920643] Key type lgssc registered [ 517.469545] Lustre: Echo OBD driver; http://www.lustre.org/ [ 521.413431] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 524.541153] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 527.857378] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 531.874377] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 531.909573] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 531.922122] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 533.117226] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 533.135652] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 533.191527] Lustre: lustre-MDT0000: new disk, initializing [ 533.247725] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 533.260344] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 535.628863] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 540.135432] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 544.082776] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 544.145586] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 544.295110] Lustre: lustre-OST0000: new disk, initializing [ 544.297301] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 544.304246] Lustre: Skipped 1 previous similar message [ 544.348319] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 546.214989] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 546.221294] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 546.242385] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 547.799669] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 552.491622] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 554.925472] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 555.078254] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 556.512927] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 556.528838] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 561.633438] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 562.289127] LustreError: 31350:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 562.358876] Lustre: server umount lustre-OST0000 complete [ 564.533118] LustreError: 31552:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 564.536023] LustreError: 31552:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 564.624598] Lustre: server umount lustre-MDT0000 complete [ 569.622996] Lustre: DEBUG MARKER: == conf-sanity test 123ai: llog_print display all non skipped records ========================================================== 09:23:46 (1773235426) [ 573.315106] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 573.556392] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 575.341413] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 578.203726] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 581.394375] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 581.601416] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 584.242516] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 586.636224] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 589.668592] LustreError: 33664:0:(llog.c:441:llog_init_handle()) llog type is not specified! [ 590.139292] Lustre: Modifying parameter general.timeout=1 in log params [ 591.442906] Lustre: Modifying parameter general.timeout=4 in log params [ 591.445572] Lustre: Skipped 2 previous similar messages [ 593.648348] Lustre: Modifying parameter general.timeout=9 in log params [ 593.654430] Lustre: Skipped 4 previous similar messages [ 597.773592] Lustre: Modifying parameter general.timeout=18 in log params [ 597.775775] Lustre: Skipped 8 previous similar messages [ 605.910889] Lustre: Modifying parameter general.timeout=38 in log params [ 605.913270] Lustre: Skipped 19 previous similar messages [ 622.266123] Lustre: Modifying parameter general.timeout=78 in log params [ 622.269159] Lustre: Skipped 39 previous similar messages [ 648.256237] Lustre: DEBUG MARKER: == conf-sanity test 123aj: check permanent TBF rules ===== 09:25:05 (1773235505) [ 650.034275] Lustre: 40561:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/ost.OSS.ost_io.nrs_tbf_rule= start rule4 jobid={fio.0.0} rate=500 (mode = 2) failed: rc = -17 [ 651.060392] Lustre: 40660:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/ost.OSS.ost_io.nrs_tbf_rule= start rule2 nid={10.10.2.20@tcp} rate=1000 (mode = 2) failed: rc = -17 [ 652.939472] Lustre: 40856:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/ost.OSS.ost_io.nrs_tbf_rule=start rule1 uid={500 502 } rate=1000 (mode = 2) failed: rc = -17 [ 652.947232] Lustre: 40856:0:(mgs_llog.c:1346:mgs_modify_param()) Skipped 1 previous similar message [ 654.306700] Lustre: Setting parameter general.ost.OSS.ost_io.nrs_tbf_rule=change rule4 rate=5000 in log params [ 654.309959] Lustre: Skipped 58 previous similar messages [ 667.721091] Lustre: 42407:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/ost.OSS.ost_io.nrs_tbf_rule= (mode = 1) failed: rc = -2 [ 667.726548] Lustre: 42407:0:(mgs_llog.c:1346:mgs_modify_param()) Skipped 2 previous similar messages [ 667.734803] LustreError: 42407:0:(mgs_handler.c:1126:mgs_iocontrol()) MGS: setparam err: rc = -2 [ 669.450590] Lustre: DEBUG MARKER: == conf-sanity test 123F: clear and reset all parameters using set_param -F ========================================================== 09:25:27 (1773235527) [ 674.785847] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 674.793360] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 679.904471] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 680.259793] LustreError: 43053:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 680.263505] LustreError: 43053:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 680.353413] Lustre: server umount lustre-MDT0000 complete [ 681.916976] LustreError: 32251:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773235540 with bad export cookie 5321892649514452423 [ 681.919915] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 681.924667] LustreError: 32251:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 682.014091] Lustre: server umount lustre-OST0000 complete [ 685.844072] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 687.602226] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 689.487883] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 692.838823] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 693.016481] Lustre: MGS: Logs for fs lustre were removed by user request. All servers must be restarted in order to regenerate the logs: rc = 0 [ 693.155146] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 695.056120] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 697.918482] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 701.247124] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 701.386498] Lustre: MGS: Regenerating lustre-OST0000 log by user request: rc = 0 [ 701.563125] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 704.148919] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 706.379629] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 707.016238] Lustre: 45912:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/jobid_var=TESTNAME (mode = 0) failed: rc = -17 [ 712.170570] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 712.170847] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 712.177102] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 715.826133] LustreError: 46164:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 715.829303] LustreError: 46164:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 715.885478] Lustre: server umount lustre-OST0000 complete [ 718.021684] Lustre: server umount lustre-MDT0000 complete [ 723.518046] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 724.795380] Key type lgssc unregistered [ 724.947757] LNet: 46898:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 724.950549] LNetError: 46898:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 724.957575] LNet: Removed LNI 192.168.204.138@tcp [ 725.355083] Key type .llcrypt unregistered [ 725.357246] Key type ._llcrypt unregistered [ 737.210126] Key type ._llcrypt registered [ 737.211043] Key type .llcrypt registered [ 737.265177] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 737.838066] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 737.906116] alg: No test for adler32 (adler32-zlib) [ 738.844673] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 738.997875] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 740.624592] Key type lgssc registered [ 741.275601] Lustre: Echo OBD driver; http://www.lustre.org/ [ 745.238980] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 745.248949] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 746.487269] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 748.228738] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 750.523594] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 753.409995] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 753.647366] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 756.044710] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 758.391476] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 763.657223] Lustre: Modifying parameter general.jobid_var=TESTNAME in log params [ 771.041308] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 771.046672] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 772.740147] LustreError: 50118:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 772.800820] Lustre: server umount lustre-MDT0000 complete [ 774.386685] LustreError: 48248:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773235632 with bad export cookie 12656655852460283420 [ 774.387548] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 774.396309] LustreError: 48248:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 774.426216] LustreError: 50322:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 774.429105] LustreError: 50322:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 774.487195] Lustre: server umount lustre-OST0000 complete [ 778.182120] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 779.811390] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 781.614730] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 785.173537] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 785.372827] Lustre: MGS: Logs for fs lustre were removed by user request. All servers must be restarted in order to regenerate the logs: rc = 0 [ 785.400922] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 785.584374] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 787.518892] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 790.154044] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 793.497460] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 793.583725] Lustre: MGS: Regenerating lustre-OST0000 log by user request: rc = 0 [ 793.771808] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 796.772787] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 799.424397] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 805.800423] Lustre: 52984:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify lustre-MDT0000/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 806.768480] Lustre: Modifying parameter general.jobid_var=disable in log params [ 813.026647] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 813.027547] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 813.038667] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 818.146063] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 823.263717] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 823.265033] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 823.287111] LustreError: 53233:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 823.289783] LustreError: 53233:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 823.344103] Lustre: server umount lustre-OST0000 complete [ 825.267837] Lustre: server umount lustre-MDT0000 complete [ 830.228632] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 831.543519] Key type lgssc unregistered [ 831.694648] LNet: 53970:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 831.703021] LNetError: 53970:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 831.711644] LNet: Removed LNI 192.168.204.138@tcp [ 832.111528] Key type .llcrypt unregistered [ 832.113626] Key type ._llcrypt unregistered [ 843.185688] Key type ._llcrypt registered [ 843.188194] Key type .llcrypt registered [ 843.243552] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 843.818324] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 843.824700] alg: No test for adler32 (adler32-zlib) [ 844.758598] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 844.897240] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 846.511170] Key type lgssc registered [ 847.049605] Lustre: Echo OBD driver; http://www.lustre.org/ [ 850.988280] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 851.002842] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 852.300052] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 854.281225] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 856.861990] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 860.197194] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 860.443767] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 863.081461] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 865.841344] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 870.731525] Lustre: Modifying parameter general.jobid_var=TEST_123H in log params [ 871.566574] Lustre: Modifying parameter general.jobid_var=TEST_123H in log params [ 871.569312] Lustre: Skipped 1 previous similar message [ 872.879817] Lustre: Modifying parameter general.jobid_var=jobid_var=disable in log params [ 872.882061] Lustre: Skipped 2 previous similar messages [ 875.083035] Lustre: Modifying parameter general.jobid_var=TEST_123H in log params [ 875.085875] Lustre: Skipped 4 previous similar messages [ 879.100330] Lustre: Modifying parameter general.jobid_var=TEST_123H in log params [ 879.103296] Lustre: Skipped 9 previous similar messages [ 887.146822] Lustre: Modifying parameter general.jobid_var=jobid_var=disable in log params [ 887.149977] Lustre: Skipped 20 previous similar messages [ 903.508580] Lustre: Modifying parameter general.jobid_var=TEST_123H in log params [ 903.510261] Lustre: Skipped 36 previous similar messages [ 916.393282] Lustre: 62273:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/jobid_var=jobid_var=disable (mode = 0) failed: rc = -17 [ 917.464497] Lustre: DEBUG MARKER: == conf-sanity test 124: check failover after replace_nids ========================================================== 09:29:35 (1773235775) [ 918.023596] Lustre: DEBUG MARKER: SKIP: conf-sanity test_124 needs >= 2 MDTs [ 918.673147] Lustre: DEBUG MARKER: == conf-sanity test 126: mount in parallel shouldn't cause a crash ========================================================== 09:29:36 (1773235776) [ 924.129554] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 924.130049] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 924.139831] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 929.250085] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 934.367193] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 934.371805] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 934.394267] LustreError: 62565:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 934.449463] Lustre: server umount lustre-OST0000 complete [ 936.135768] LustreError: 62768:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 936.138033] LustreError: 62768:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 936.210304] Lustre: server umount lustre-MDT0000 complete [ 941.055920] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 942.440398] Key type lgssc unregistered [ 942.599312] LNet: 63299:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 942.601751] LNetError: 63299:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 942.615130] LNet: Removed LNI 192.168.204.138@tcp [ 943.014462] Key type .llcrypt unregistered [ 943.016081] Key type ._llcrypt unregistered [ 944.887501] Key type ._llcrypt registered [ 944.888598] Key type .llcrypt registered [ 944.949186] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_module ../libcfs/libcfs/libcfs [ 946.690869] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules [ 947.096600] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 947.140123] alg: No test for adler32 (adler32-zlib) [ 948.046513] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 948.154079] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 949.759423] Key type lgssc registered [ 950.275701] Lustre: Echo OBD driver; http://www.lustre.org/ [ 950.810927] LustreError: 64413:0:(lu_object.c:1438:lu_context_key_register()) cfs_race id 60d sleeping [ 960.032509] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 964.010308] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 972.120787] LustreError: 64413:0:(lu_object.c:1438:lu_context_key_register()) cfs_fail_race id 60d awake: rc=0 [ 972.135608] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 973.459974] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 975.199787] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 978.992592] Lustre: DEBUG MARKER: == conf-sanity test 127: direct io overwrite on full ost ========================================================== 09:30:36 (1773235836) [ 981.104433] LustreError: 66220:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 981.165344] Lustre: server umount lustre-MDT0000 complete [ 986.007331] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 987.529581] Key type lgssc unregistered [ 987.691619] LNet: 66754:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 987.697961] LNetError: 66754:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 987.707591] LNet: Removed LNI 192.168.204.138@tcp [ 988.143450] Key type .llcrypt unregistered [ 988.145077] Key type ._llcrypt unregistered [ 997.709868] Key type ._llcrypt registered [ 997.711738] Key type .llcrypt registered [ 997.769924] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 998.237910] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 998.279364] alg: No test for adler32 (adler32-zlib) [ 999.186479] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 999.324579] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 1000.943153] Key type lgssc registered [ 1001.504749] Lustre: Echo OBD driver; http://www.lustre.org/ [ 1005.011146] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 1005.022979] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1006.281383] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1008.135882] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1011.232768] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1014.399673] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1014.753096] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1017.751265] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1020.612283] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 1046.112661] Lustre: DEBUG MARKER: == conf-sanity test 128: Force using remote logs with --nolocallogs ========================================================== 09:31:43 (1773235903) [ 1046.730575] Lustre: DEBUG MARKER: SKIP: conf-sanity test_128 need separate mgs device [ 1047.365499] Lustre: DEBUG MARKER: == conf-sanity test 129: attempt to connect an OST with the same index should fail ========================================================== 09:31:45 (1773235905) [ 1051.616638] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1051.622717] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1054.661955] LustreError: 69982:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 1054.754387] Lustre: server umount lustre-MDT0000 complete [ 1056.277253] LustreError: 67909:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773235914 with bad export cookie 17903901444418931882 [ 1056.278682] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1056.281919] LustreError: 67909:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1056.315710] LustreError: 70183:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 1056.318444] LustreError: 70183:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1056.444720] Lustre: server umount lustre-OST0000 complete [ 1060.945755] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1061.254951] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1062.734783] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1064.706890] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1067.235440] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1069.916563] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1069.951583] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1070.035993] LustreError: Server lustre-OST0000 requested index 0, but that index is already in use. Use --writeconf to force [ 1070.040576] LustreError: 70801:0:(mgs_handler.c:567:mgs_target_reg()) Failed to write lustre-OST0000 log (-98) [ 1070.051253] LustreError: lustre-OST0000: the MGS refuses to allow this server to start: rc = -98. Please see messages on the MGS. [ 1070.054134] LustreError: 71874:0:(tgt_mount.c:2479:server_fill_super()) Unable to start targets: -98 [ 1070.056730] LustreError: 71874:0:(tgt_mount.c:1973:server_put_super()) no obd lustre-OST0000 [ 1070.058701] LustreError: 71874:0:(tgt_mount.c:117:server_deregister_mount()) lustre-OST0000 not registered [ 1070.088072] Lustre: server umount lustre-OST0000 complete [ 1070.090448] LustreError: 71874:0:(super25.c:199:lustre_fill_super()) llite: Unable to mount : rc = -98 [ 1073.621273] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1073.725654] LustreError: Server lustre-OST0000 requested index 0, but that index is already in use. Use --writeconf to force [ 1073.729095] LustreError: 70802:0:(mgs_handler.c:567:mgs_target_reg()) Failed to write lustre-OST0000 log (-98) [ 1073.736850] LustreError: lustre-OST0000: the MGS refuses to allow this server to start: rc = -98. Please see messages on the MGS. [ 1073.742072] LustreError: 72339:0:(tgt_mount.c:2479:server_fill_super()) Unable to start targets: -98 [ 1073.745921] LustreError: 72339:0:(tgt_mount.c:1973:server_put_super()) no obd lustre-OST0000 [ 1073.748796] LustreError: 72339:0:(tgt_mount.c:117:server_deregister_mount()) lustre-OST0000 not registered [ 1073.773671] Lustre: server umount lustre-OST0000 complete [ 1073.776103] LustreError: 72339:0:(super25.c:199:lustre_fill_super()) llite: Unable to mount : rc = -98 [ 1074.880298] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1077.482346] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1077.547672] Lustre: MGS: Regenerating lustre-OST0000 log by user request: rc = 0 [ 1077.549939] Lustre: Found index 0 for lustre-OST0000, updating log [ 1077.552108] Lustre: Client log for lustre-OST0000 was not updated; writeconf the MDT first to regenerate it. [ 1077.574638] Lustre: lustre-OST0000: new disk, initializing [ 1077.576767] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1077.669764] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1079.849235] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1081.319397] Lustre: Failing over lustre-OST0000 [ 1081.340082] LustreError: 73414:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 1081.342429] LustreError: 73414:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1081.376193] Lustre: server umount lustre-OST0000 complete [ 1083.044477] Lustre: server umount lustre-MDT0000 complete [ 1086.394346] Lustre: DEBUG MARKER: == conf-sanity test 130: re-register an MDT after writeconf ========================================================== 09:32:24 (1773235944) [ 1087.071614] Lustre: DEBUG MARKER: SKIP: conf-sanity test_130 needs >= 2 MDTs [ 1087.765967] Lustre: DEBUG MARKER: == conf-sanity test 131: MDT backup restore with project ID ========================================================== 09:32:25 (1773235945) [ 1093.630745] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 1097.597572] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1097.814064] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1099.288192] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1100.460699] Lustre: Setting parameter general.debug_raw_pointers=Y in log params [ 1102.779349] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1105.009227] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1108.317582] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1108.353426] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1108.384304] Lustre: MGS: Regenerating lustre-OST0001 log by user request: rc = 0 [ 1108.427374] Lustre: lustre-OST0001: new disk, initializing [ 1108.430196] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1108.551815] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 1108.554137] Lustre: Skipped 1 previous similar message [ 1110.877532] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1113.102474] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 1113.108306] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 1113.129771] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 1114.371297] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1118.393273] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1179.616637] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1179.617142] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1179.620236] Lustre: Skipped 1 previous similar message [ 1179.623688] Lustre: Skipped 1 previous similar message [ 1184.109510] LustreError: 77935:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 1184.116685] LustreError: 77935:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1184.194967] Lustre: server umount lustre-MDT0000 complete [ 1185.762154] LustreError: 75048:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773236044 with bad export cookie 17903901444418934871 [ 1185.764502] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1185.766298] LustreError: 75048:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1185.822182] Lustre: server umount lustre-OST0000 complete [ 1187.394730] Lustre: server umount lustre-OST0001 complete [ 1189.808884] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1193.182361] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1193.557176] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1200.137755] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 1204.024141] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1204.031685] Lustre: lustre-MDT0000: reset Object Index mappings [ 1204.239199] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1205.836311] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1207.081886] Lustre: 80712:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1209.621747] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1212.446782] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1214.057324] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:515 to 0x240000400:546) [ 1215.999661] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1218.124267] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:322 to 0x280000400:353) [ 1219.213261] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1223.307403] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1224.990964] Lustre: 82551:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1248.433530] Lustre: DEBUG MARKER: == conf-sanity test 132: hsm_actions processed after failover ========================================================== 09:35:06 (1773236106) [ 1277.920102] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1277.920687] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1277.924026] Lustre: Skipped 1 previous similar message [ 1283.041069] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1283.043800] Lustre: Skipped 2 previous similar messages [ 1283.346606] LustreError: 82900:0:(obd_class.h:479:obd_check_dev()) Device 9 not setup [ 1283.349388] LustreError: 82900:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 1283.415572] Lustre: server umount lustre-MDT0000 complete [ 1284.999184] LustreError: 80287:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773236143 with bad export cookie 17903901444418980273 [ 1285.004298] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1285.004300] LustreError: 80287:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1291.142837] Lustre: server umount lustre-OST0000 complete [ 1298.673359] LustreError: 83303:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 1298.675938] LustreError: 83303:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1298.718922] Lustre: server umount lustre-OST0001 complete [ 1301.075208] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 1304.308240] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 1307.867716] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1310.097579] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1312.536236] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1315.000277] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1315.022397] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1315.107828] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1315.120276] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1315.161433] Lustre: lustre-MDT0000: new disk, initializing [ 1315.185393] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1315.188435] Lustre: Skipped 2 previous similar messages [ 1315.195153] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1316.515604] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1319.529180] LustreError: 85796:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 1319.531443] LustreError: 85796:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 1319.584776] Lustre: server umount lustre-MDT0000 complete [ 1320.590773] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1322.995655] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1323.018739] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1323.111064] Lustre: Found index 0 for lustre-MDT0000, updating log [ 1323.117100] Lustre: 86316:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify lustre-MDT0000/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1323.123744] Lustre: Setting parameter lustre-MDT0000.mdt.hsm_control=enabled in log lustre-MDT0000 [ 1324.634529] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1326.419106] Lustre: server umount lustre-MDT0000 complete [ 1329.546404] Lustre: DEBUG MARKER: == conf-sanity test 133: stripe QOS: free space balance in a pool ========================================================== 09:36:27 (1773236187) [ 1330.140898] Lustre: DEBUG MARKER: SKIP: conf-sanity test_133 needs >= 4 OSTs [ 1330.783098] Lustre: DEBUG MARKER: == conf-sanity test 134: check_iam works without faults == 09:36:28 (1773236188) [ 1336.062628] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 1340.059151] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1341.704313] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1342.837756] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1345.464197] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1345.497554] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1345.619317] Lustre: lustre-OST0000: new disk, initializing [ 1345.621820] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1345.624400] Lustre: Skipped 1 previous similar message [ 1346.838105] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 1346.842301] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 1346.859594] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 1347.896975] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1352.445796] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1352.474433] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1352.535519] Lustre: lustre-OST0001: new disk, initializing [ 1352.538034] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1353.628226] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 1353.632800] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 1353.646388] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 1354.782772] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1359.455594] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1360.787338] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1479.325528] Lustre: 96249:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 9: before 516 < left 1024, rollback = 8 [ 1479.329629] Lustre: 96249:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 1479.331923] Lustre: 96249:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/1/0 [ 1479.335654] Lustre: 96249:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 1/3/0 [ 1479.339083] Lustre: 96249:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 0/0/0, delete: 256/1024/0 [ 1479.342621] Lustre: 96249:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1553.917348] Lustre: DEBUG MARKER: == conf-sanity test 135: check the behavior when changelog is wrapped around ========================================================== 09:40:11 (1773236411) [ 1568.737291] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1568.738825] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1568.741482] Lustre: Skipped 1 previous similar message [ 1571.716342] LustreError: 96452:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 1571.718691] LustreError: 96452:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 1571.812076] Lustre: server umount lustre-MDT0000 complete [ 1573.648093] LustreError: 88267:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773236431 with bad export cookie 17903901444419035160 [ 1573.649314] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1573.653985] LustreError: 88267:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1579.783271] Lustre: server umount lustre-OST0000 complete [ 1587.487920] Lustre: server umount lustre-OST0001 complete [ 1590.357746] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 1594.185378] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 1598.337617] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1601.315499] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1604.216398] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1607.262204] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1607.289432] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1607.409833] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1607.429966] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1607.469575] Lustre: lustre-MDT0000: new disk, initializing [ 1607.497530] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1607.499920] Lustre: Skipped 4 previous similar messages [ 1607.507518] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1609.222648] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1613.163958] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1616.495028] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1616.553607] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1618.009454] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 1618.014115] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 1618.027705] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 1619.356609] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 1623.190766] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 1626.891442] Lustre: lustre-MDD0000: changelog on [ 1628.295963] Lustre: 98775:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 515 < left 539, rollback = 2 [ 1628.301835] Lustre: 98775:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 255 previous similar messages [ 1628.304837] Lustre: 98775:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 3/12/0, destroy: 0/0/0 [ 1628.307125] Lustre: 98775:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 255 previous similar messages [ 1628.309396] Lustre: 98775:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 4/4/0, xattr_set: 9/539/0 [ 1628.311538] Lustre: 98775:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 255 previous similar messages [ 1628.315591] Lustre: 98775:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 10/93/1, punch: 0/0/0, quota 1/3/0 [ 1628.318424] Lustre: 98775:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 255 previous similar messages [ 1628.320418] Lustre: 98775:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 4/67/0, delete: 0/0/0 [ 1628.322352] Lustre: 98775:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 255 previous similar messages [ 1628.324967] Lustre: 98775:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1628.328857] Lustre: 98775:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 255 previous similar messages [ 1629.297279] Lustre: 98776:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 516 < left 525, rollback = 2 [ 1629.302223] Lustre: 98776:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 755 previous similar messages [ 1629.304972] Lustre: 98776:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 1629.308606] Lustre: 98776:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 755 previous similar messages [ 1629.311728] Lustre: 98776:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1629.315164] Lustre: 98776:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 755 previous similar messages [ 1629.318415] Lustre: 98776:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/0, punch: 0/0/0, quota 1/3/0 [ 1629.321130] Lustre: 98776:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 755 previous similar messages [ 1629.324037] Lustre: 98776:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/0, delete: 0/0/0 [ 1629.326619] Lustre: 98776:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 755 previous similar messages [ 1629.330216] Lustre: 98776:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1629.334786] Lustre: 98776:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 755 previous similar messages [ 1631.298484] Lustre: 98805:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 516 < left 525, rollback = 2 [ 1631.301538] Lustre: 98805:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 1733 previous similar messages [ 1631.304047] Lustre: 98805:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 1631.305969] Lustre: 98805:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 1733 previous similar messages [ 1631.312037] Lustre: 98805:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1631.314469] Lustre: 98805:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 1737 previous similar messages [ 1631.320103] Lustre: 98805:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/0, punch: 0/0/0, quota 1/3/0 [ 1631.323413] Lustre: 98805:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 1739 previous similar messages [ 1631.325877] Lustre: 98805:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/0, delete: 0/0/0 [ 1631.328262] Lustre: 98805:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 1739 previous similar messages [ 1631.331437] Lustre: 98805:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1631.334543] Lustre: 98805:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 1739 previous similar messages [ 1635.300393] Lustre: 98777:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 516 < left 525, rollback = 2 [ 1635.303537] Lustre: 98777:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 3131 previous similar messages [ 1635.306718] Lustre: 98777:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 1635.309691] Lustre: 98777:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 3131 previous similar messages [ 1635.312359] Lustre: 98777:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1635.314765] Lustre: 98777:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 3127 previous similar messages [ 1635.322045] Lustre: 98777:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/0, punch: 0/0/0, quota 1/3/0 [ 1635.325704] Lustre: 98777:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 3128 previous similar messages [ 1635.329745] Lustre: 98777:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/0, delete: 0/0/0 [ 1635.333523] Lustre: 98777:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 3128 previous similar messages [ 1635.337511] Lustre: 98777:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1635.341273] Lustre: 98777:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 3128 previous similar messages [ 1643.306674] Lustre: 98805:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 516 < left 525, rollback = 2 [ 1643.311963] Lustre: 98805:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 6095 previous similar messages [ 1643.323722] Lustre: 98805:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 1643.327735] Lustre: 98805:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 6095 previous similar messages [ 1643.330759] Lustre: 98805:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1643.333975] Lustre: 98805:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 6095 previous similar messages [ 1643.337501] Lustre: 98805:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/0, punch: 0/0/0, quota 1/3/0 [ 1643.340313] Lustre: 98805:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 6092 previous similar messages [ 1643.342988] Lustre: 98805:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/0, delete: 0/0/0 [ 1643.345924] Lustre: 98805:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 6092 previous similar messages [ 1643.348368] Lustre: 98805:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1643.350275] Lustre: 98805:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 6092 previous similar messages [ 1659.307784] Lustre: 98777:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 516 < left 525, rollback = 2 [ 1659.311619] Lustre: 98777:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 2762 previous similar messages [ 1659.324540] Lustre: 98777:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 1659.327980] Lustre: 98777:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 2771 previous similar messages [ 1659.331553] Lustre: 98777:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1659.335401] Lustre: 98777:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 2771 previous similar messages [ 1659.338920] Lustre: 98777:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/0, punch: 0/0/0, quota 1/3/0 [ 1659.342669] Lustre: 98777:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 2771 previous similar messages [ 1659.346195] Lustre: 98777:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/0, delete: 0/0/0 [ 1659.349051] Lustre: 98777:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 2771 previous similar messages [ 1659.352485] Lustre: 98777:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1659.355699] Lustre: 98777:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 2771 previous similar messages [ 1692.926511] Lustre: 100840:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 514 < left 525, rollback = 2 [ 1692.930120] Lustre: 100840:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 12518 previous similar messages [ 1692.932853] Lustre: 100840:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 1692.935521] Lustre: 100840:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 12509 previous similar messages [ 1692.938586] Lustre: 100840:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1692.942031] Lustre: 100840:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 12509 previous similar messages [ 1692.944938] Lustre: 100840:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/1, punch: 0/0/0, quota 1/3/0 [ 1692.947970] Lustre: 100840:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 12509 previous similar messages [ 1692.951147] Lustre: 100840:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/1, delete: 0/0/0 [ 1692.956319] Lustre: 100840:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 12509 previous similar messages [ 1692.959592] Lustre: 100840:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1692.962146] Lustre: 100840:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 12509 previous similar messages [ 1758.457757] Lustre: 100840:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 508 < left 525, rollback = 2 [ 1758.463695] Lustre: 100840:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 26999 previous similar messages [ 1758.468497] Lustre: 100840:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/6, destroy: 0/0/0 [ 1758.473226] Lustre: 100840:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 26999 previous similar messages [ 1758.478251] Lustre: 100840:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1758.483294] Lustre: 100840:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 26999 previous similar messages [ 1758.488288] Lustre: 100840:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/1, punch: 0/0/0, quota 1/3/0 [ 1758.493315] Lustre: 100840:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 26999 previous similar messages [ 1758.498171] Lustre: 100840:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/1, delete: 0/0/0 [ 1758.502803] Lustre: 100840:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 26999 previous similar messages [ 1758.508050] Lustre: 100840:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1758.513036] Lustre: 100840:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 26999 previous similar messages [ 1889.569216] Lustre: 98805:0:(osd_internal.h:1471:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 514 < left 525, rollback = 2 [ 1889.572192] Lustre: 98805:0:(osd_internal.h:1471:osd_trans_exec_op()) Skipped 67499 previous similar messages [ 1889.574555] Lustre: 98805:0:(osd_handler.c:2081:osd_trans_dump_creds()) create: 2/8/0, destroy: 0/0/0 [ 1889.577120] Lustre: 98805:0:(osd_handler.c:2081:osd_trans_dump_creds()) Skipped 67499 previous similar messages [ 1889.579932] Lustre: 98805:0:(osd_handler.c:2088:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 7/525/0 [ 1889.582711] Lustre: 98805:0:(osd_handler.c:2088:osd_trans_dump_creds()) Skipped 67499 previous similar messages [ 1889.585091] Lustre: 98805:0:(osd_handler.c:2098:osd_trans_dump_creds()) write: 7/39/1, punch: 0/0/0, quota 1/3/0 [ 1889.588088] Lustre: 98805:0:(osd_handler.c:2098:osd_trans_dump_creds()) Skipped 67499 previous similar messages [ 1889.591035] Lustre: 98805:0:(osd_handler.c:2105:osd_trans_dump_creds()) insert: 3/50/1, delete: 0/0/0 [ 1889.593562] Lustre: 98805:0:(osd_handler.c:2105:osd_trans_dump_creds()) Skipped 67499 previous similar messages [ 1889.596434] Lustre: 98805:0:(osd_handler.c:2112:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1889.598969] Lustre: 98805:0:(osd_handler.c:2112:osd_trans_dump_creds()) Skipped 67499 previous similar messages [ 2117.810728] Lustre: 100840:0:(llog_cat.c:971:llog_cat_process_or_fork()) lustre-MDD0000: catlog [0xa:0x5:0x0] crosses index zero [ 2149.306194] Lustre: lustre-MDD0000: changelog off [ 2155.488618] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2155.490907] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2155.494445] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2155.496181] Lustre: Skipped 1 previous similar message [ 2165.215114] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2165.231116] LustreError: 107242:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 2165.234155] LustreError: 107242:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 2165.272340] Lustre: server umount lustre-OST0000 complete [ 2166.559365] Lustre: server umount lustre-MDT0000 complete [ 2169.859789] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 2170.867182] Key type lgssc unregistered [ 2170.994779] LNet: 107975:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2170.996868] LNetError: 107975:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2171.004297] LNet: Removed LNI 192.168.204.138@tcp [ 2171.299130] Key type .llcrypt unregistered [ 2171.300696] Key type ._llcrypt unregistered [ 2181.529611] Key type ._llcrypt registered [ 2181.530865] Key type .llcrypt registered [ 2181.573065] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2181.926535] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 2181.958793] alg: No test for adler32 (adler32-zlib) [ 2182.838184] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 2182.934673] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 2184.511156] Key type lgssc registered [ 2184.828783] Lustre: Echo OBD driver; http://www.lustre.org/ [ 2187.108442] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 2187.113045] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2188.249652] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2189.409307] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2190.999098] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2193.010719] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2193.110648] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2194.911052] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2196.619566] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2198.245109] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:85502 to 0x240000400:85537) [ 2198.307233] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x240000400 to 0x240000401 [ 2206.278426] Lustre: DEBUG MARKER: == conf-sanity test 151a: damaged local config doesn't prevent mounting ========================================================== 09:51:04 (1773237064) [ 2208.736506] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2208.736615] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2208.743566] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2213.163160] LustreError: 111131:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 2213.194971] Lustre: server umount lustre-OST0000 complete [ 2214.363710] LustreError: 111333:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 2214.365643] LustreError: 111333:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 2214.409010] Lustre: server umount lustre-MDT0000 complete [ 2217.539833] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 2218.462742] Key type lgssc unregistered [ 2218.572347] LNet: 111863:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2218.574414] LNetError: 111863:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2218.581493] LNet: Removed LNI 192.168.204.138@tcp [ 2218.835512] Key type .llcrypt unregistered [ 2218.836494] Key type ._llcrypt unregistered [ 2225.407266] Key type ._llcrypt registered [ 2225.408238] Key type .llcrypt registered [ 2225.446652] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2225.751731] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 2225.777877] alg: No test for adler32 (adler32-zlib) [ 2226.614267] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 2226.685237] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 2228.255145] Key type lgssc registered [ 2228.629540] Lustre: Echo OBD driver; http://www.lustre.org/ [ 2231.201427] Lustre: lustre-OST0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 2231.208459] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2246.623271] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2251.743146] LustreError: 113062:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.204.138@tcp: failed processing log, type 4: rc = -110 [ 2256.863369] LustreError: 113062:0:(llog_osd.c:246:llog_osd_read_header()) lustre-OST0000-osd: bad log lustre-OST0000 [0xa:0x6:0x0] header magic: 0x0 (expected 0x10645539) [ 2256.867136] LustreError: Failed to get MGS log lustre-OST0000 and no local copy. [ 2256.869135] LustreError: MGC192.168.204.138@tcp: Configuration from log lustre-OST0000 failed from MGS -22. Check client and MGS are on compatible version. [ 2256.872085] LustreError: 113062:0:(tgt_mount.c:1729:server_start_targets()) failed to start server lustre-OST0000: -22 [ 2256.874381] LustreError: 113062:0:(tgt_mount.c:2479:server_fill_super()) Unable to start targets: -22 [ 2256.876709] LustreError: 113062:0:(tgt_mount.c:1973:server_put_super()) no obd lustre-OST0000 [ 2256.879505] LustreError: 113062:0:(obd_class.h:479:obd_check_dev()) Device 1 not setup [ 2256.899973] Lustre: server umount lustre-OST0000 complete [ 2256.901343] LustreError: 113062:0:(super25.c:199:lustre_fill_super()) llite: Unable to mount : rc = -22 [ 2259.569051] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2260.715123] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2261.930171] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2263.521646] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2265.668598] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2265.731578] LustreError: 114358:0:(llog_osd.c:246:llog_osd_read_header()) lustre-OST0000-osd: bad log lustre-OST0000 [0xa:0x6:0x0] header magic: 0x0 (expected 0x10645539) [ 2265.734103] Lustre: 114358:0:(mgc_request_server.c:712:mgc_llog_local_copy()) MGC192.168.204.138@tcp: invalid local config log lustre-OST0000: rc = -22 [ 2265.769025] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2267.554521] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2269.253592] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2269.977685] LustreError: 115003:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 2269.979477] LustreError: 115003:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 2270.023502] Lustre: server umount lustre-MDT0000 complete [ 2271.279378] LustreError: 113544:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773237129 with bad export cookie 14322967731562924781 [ 2271.283791] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2281.456420] LustreError: 115207:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 2281.458679] LustreError: 115207:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2281.498279] Lustre: server umount lustre-OST0000 complete [ 2284.503651] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 2287.378791] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2290.473944] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2292.350618] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2294.298196] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2296.310686] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2296.332745] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2296.403908] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2296.414225] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2296.446454] Lustre: lustre-MDT0000: new disk, initializing [ 2296.469437] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2296.475549] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2297.673905] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2300.580918] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2302.607947] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2302.625509] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2302.715475] Lustre: lustre-OST0000: new disk, initializing [ 2302.717584] Lustre: lustre-OST0000: Not available for connect from 0@lo (not set up) [ 2302.719710] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2302.722454] Lustre: Skipped 1 previous similar message [ 2302.742060] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2304.379431] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2307.266497] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2308.079700] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 2308.082731] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2308.091670] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2308.469839] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 2308.534844] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 2313.184509] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2313.184816] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2313.189959] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2315.179072] LustreError: 119105:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 2315.181344] LustreError: 119105:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2315.213924] Lustre: server umount lustre-OST0000 complete [ 2316.387608] Lustre: server umount lustre-MDT0000 complete [ 2318.815877] Lustre: DEBUG MARKER: == conf-sanity test 151b: -ENOSPC doesn't affect mount === 09:52:56 (1773237176) [ 2322.877214] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 2323.736900] Key type lgssc unregistered [ 2323.847316] LNet: 120338:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2323.849176] LNetError: 120338:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2323.859259] LNet: Removed LNI 192.168.204.138@tcp [ 2324.122540] Key type .llcrypt unregistered [ 2324.123642] Key type ._llcrypt unregistered [ 2330.691652] Key type ._llcrypt registered [ 2330.692829] Key type .llcrypt registered [ 2330.728617] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2331.061675] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 2331.104339] alg: No test for adler32 (adler32-zlib) [ 2331.957052] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 2332.037737] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 2333.615108] Key type lgssc registered [ 2333.955849] Lustre: Echo OBD driver; http://www.lustre.org/ [ 2336.561769] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 2336.568967] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2337.722829] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2339.051969] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2340.826886] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2343.176633] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2343.241548] Lustre: *** cfs_fail_loc=131e, val=0*** [ 2343.242990] LustreError: 122356:0:(llog.c:1657:llog_backup()) MGC192.168.204.138@tcp: failed to backup log lustre-OST0000: rc = -28 [ 2343.246208] Lustre: 122356:0:(mgc_request_server.c:709:mgc_llog_local_copy()) MGC192.168.204.138@tcp: can't backup local config lustre-OST0000: rc = -28 [ 2343.277653] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2344.975491] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2346.630541] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2347.349371] LustreError: 123001:0:(obd_class.h:479:obd_check_dev()) Device 8 not setup [ 2347.391942] Lustre: server umount lustre-MDT0000 complete [ 2348.630668] LustreError: 121492:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773237206 with bad export cookie 8873585276358794409 [ 2348.636554] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2358.252241] LustreError: 123205:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 2358.253791] LustreError: 123205:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2358.284347] Lustre: server umount lustre-OST0000 complete [ 2361.236172] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 2364.146162] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2367.228772] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2369.232748] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2371.404345] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2373.582040] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2373.601027] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2373.678337] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2373.688290] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2373.729238] Lustre: lustre-MDT0000: new disk, initializing [ 2373.753860] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2373.759767] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2374.992762] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2377.978066] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2380.044800] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2380.066743] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2380.156335] Lustre: *** cfs_fail_loc=131e, val=0*** [ 2380.157387] Lustre: Skipped 1 previous similar message [ 2380.158786] LustreError: 126134:0:(llog.c:1657:llog_backup()) MGC192.168.204.138@tcp: failed to backup log lustre-OST0000: rc = -28 [ 2380.163000] LustreError: 126134:0:(llog.c:1657:llog_backup()) Skipped 1 previous similar message [ 2380.164548] Lustre: 126134:0:(mgc_request_server.c:732:mgc_llog_local_copy()) MGC192.168.204.138@tcp: failed to copy new config lustre-OST0000: rc = -28 [ 2380.174884] Lustre: lustre-OST0000: new disk, initializing [ 2380.176660] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2380.178315] Lustre: Skipped 1 previous similar message [ 2380.198203] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2381.988469] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2385.020679] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2385.390769] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 2385.394803] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2385.405354] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2386.275807] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 2386.343219] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 2390.496649] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2390.496852] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2390.502717] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2393.003846] LustreError: 127097:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 2393.005610] LustreError: 127097:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2393.035500] Lustre: server umount lustre-OST0000 complete [ 2394.317525] Lustre: server umount lustre-MDT0000 complete [ 2397.155835] Lustre: DEBUG MARKER: == conf-sanity test 152: seq allocation error in OSP ===== 09:54:14 (1773237254) [ 2397.650593] Lustre: DEBUG MARKER: SKIP: conf-sanity test_152 needs >= 2 MDTs [ 2398.200344] Lustre: DEBUG MARKER: == conf-sanity test 153a: bypass invalid NIDs quickly ==== 09:54:15 (1773237255) [ 2402.210054] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 2404.990048] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2408.136987] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2409.939906] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2411.892846] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2414.049023] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2414.071915] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2414.149343] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2414.158148] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2414.195851] Lustre: lustre-MDT0000: new disk, initializing [ 2414.217081] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2414.223075] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2415.402520] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2418.283669] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2420.355410] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2420.378751] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2420.466807] Lustre: lustre-OST0000: new disk, initializing [ 2420.468572] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2420.470247] Lustre: Skipped 1 previous similar message [ 2420.602688] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 2420.607148] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2420.615481] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2422.194336] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2425.107229] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2426.312153] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 2426.375320] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 2430.945027] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2430.945144] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2430.950249] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2436.064183] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2441.183116] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2441.184122] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2441.199088] LustreError: 131782:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 2441.201321] LustreError: 131782:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2441.233649] Lustre: server umount lustre-OST0000 complete [ 2442.489126] Lustre: server umount lustre-MDT0000 complete [ 2445.079512] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2445.227413] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2445.229504] Lustre: Skipped 1 previous similar message [ 2446.421454] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2448.078404] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2450.261882] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2452.123596] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2453.762834] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2465.760412] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2465.760594] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2465.764277] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2467.306089] LustreError: 134024:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 2467.307890] LustreError: 134024:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2467.341398] Lustre: server umount lustre-OST0000 complete [ 2470.569447] Lustre: server umount lustre-MDT0000 complete [ 2586.739540] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 2587.715684] Key type lgssc unregistered [ 2587.840298] LNet: 134796:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 2587.842597] LNetError: 134796:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 2587.850306] LNet: Removed LNI 192.168.204.138@tcp [ 2588.136707] Key type .llcrypt unregistered [ 2588.138028] Key type ._llcrypt unregistered [ 2594.694577] Key type ._llcrypt registered [ 2594.695491] Key type .llcrypt registered [ 2594.729591] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 2600.325076] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2600.634162] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 2600.666785] alg: No test for adler32 (adler32-zlib) [ 2601.515668] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 2601.596305] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 2603.175184] Key type lgssc registered [ 2603.518614] Lustre: Echo OBD driver; http://www.lustre.org/ [ 2606.048292] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2607.895281] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2609.793413] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2611.841854] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2611.864098] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 2611.868779] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2612.946851] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2612.956173] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2612.993484] Lustre: lustre-MDT0000: new disk, initializing [ 2613.016625] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2613.022131] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2614.203382] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2617.156211] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2619.371619] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2619.393657] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2619.481697] Lustre: lustre-OST0000: new disk, initializing [ 2619.483375] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2619.484920] Lustre: Skipped 1 previous similar message [ 2619.507780] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2620.989577] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 2620.992838] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2621.000854] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2621.249797] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2624.144943] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2625.424228] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 2625.496033] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 2631.136421] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2631.139026] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2631.142359] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2636.256553] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2640.351133] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2640.370099] LustreError: 139501:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 2640.402975] Lustre: server umount lustre-OST0000 complete [ 2641.690800] LustreError: 139705:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 2641.693750] LustreError: 139705:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 2641.744945] Lustre: server umount lustre-MDT0000 complete [ 2647.077298] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2650.500967] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2650.659633] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2651.992814] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2652.963741] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2655.197326] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2655.310095] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2657.193931] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2660.038664] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2660.065514] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2660.120329] Lustre: lustre-OST0001: new disk, initializing [ 2660.122722] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2660.150622] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2660.271782] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 2660.275837] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 2660.284169] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 2662.045653] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2667.397373] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2671.075831] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2679.422284] Lustre: DEBUG MARKER: == conf-sanity test 153c: don't stuck on unreached NID === 09:58:57 (1773237537) [ 2681.824597] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2681.825377] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2681.828568] Lustre: Skipped 1 previous similar message [ 2686.211575] LustreError: 143482:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 2686.213530] LustreError: 143482:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 2686.268765] Lustre: server umount lustre-MDT0000 complete [ 2687.521474] LustreError: 140805:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773237545 with bad export cookie 13183414281299752679 [ 2687.524153] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2687.525439] LustreError: 140805:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2687.555369] Lustre: server umount lustre-OST0000 complete [ 2688.760078] LustreError: 143884:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 2688.761760] LustreError: 143884:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2688.796381] Lustre: server umount lustre-OST0001 complete [ 2690.780690] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 2693.626562] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 2696.731427] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2698.733651] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2700.768368] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2703.025676] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2703.046834] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2703.127184] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 2703.137486] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 2703.174476] Lustre: lustre-MDT0000: new disk, initializing [ 2703.196791] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2703.203162] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 2704.481627] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2707.496760] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2709.716184] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2709.738700] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2709.835908] Lustre: lustre-OST0000: new disk, initializing [ 2709.839153] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2709.842744] Lustre: Skipped 1 previous similar message [ 2711.492931] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 2711.498052] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 2711.507143] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 2711.721872] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2714.749703] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2716.025906] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 2716.102843] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 2721.761142] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2721.764831] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2721.771390] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2721.773275] Lustre: Skipped 1 previous similar message [ 2726.880394] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2730.975113] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2730.991612] LustreError: 147621:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 2730.994049] LustreError: 147621:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 2731.031941] Lustre: server umount lustre-OST0000 complete [ 2732.337155] Lustre: server umount lustre-MDT0000 complete [ 2735.092186] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2735.262363] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2735.266079] Lustre: Skipped 1 previous similar message [ 2736.502709] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2738.205996] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2740.546958] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2742.586387] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 2744.383136] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2888.160902] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2888.161181] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2888.168131] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 2893.357081] LustreError: 149796:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 2893.358864] LustreError: 149796:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 2893.393278] Lustre: server umount lustre-OST0000 complete [ 2894.839833] Lustre: server umount lustre-MDT0000 complete [ 3008.345523] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3009.360810] Key type lgssc unregistered [ 3009.483322] LNet: 150568:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3009.485501] LNetError: 150568:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3009.495310] LNet: Removed LNI 192.168.204.138@tcp [ 3009.778117] Key type .llcrypt unregistered [ 3009.779214] Key type ._llcrypt unregistered [ 3016.702862] Key type ._llcrypt registered [ 3016.703817] Key type .llcrypt registered [ 3016.738478] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 3022.544038] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3022.881480] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3022.906891] alg: No test for adler32 (adler32-zlib) [ 3023.757899] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 3023.848687] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 3025.431168] Key type lgssc registered [ 3025.789918] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3028.772189] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3030.845567] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3032.941717] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3037.592042] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3040.957177] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3040.980477] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3040.986369] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3042.076163] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3042.086909] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3042.130886] Lustre: lustre-MDT0000: new disk, initializing [ 3042.155337] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3042.161511] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3043.455622] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3045.712746] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3047.897119] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3047.918158] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3048.008784] Lustre: lustre-OST0000: new disk, initializing [ 3048.010582] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3048.012406] Lustre: Skipped 1 previous similar message [ 3048.036979] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3048.331764] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 3048.335977] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 3048.345799] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 3049.908356] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3054.095201] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3054.121355] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3054.173911] Lustre: lustre-OST0001: new disk, initializing [ 3054.175723] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3054.208139] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3054.862036] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 3054.865727] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 3054.876851] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 3056.176730] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3061.776716] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3065.513565] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3075.552547] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3075.552955] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3075.555519] Lustre: Skipped 1 previous similar message [ 3075.558674] Lustre: Skipped 1 previous similar message [ 3079.424667] LustreError: 156830:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 3079.470626] Lustre: server umount lustre-MDT0000 complete [ 3080.586036] LustreError: 156524:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773237938 with bad export cookie 2627446065088870873 [ 3080.587826] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3080.589206] LustreError: 156524:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3080.609184] LustreError: 157031:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3080.610642] LustreError: 157031:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 3080.623670] Lustre: server umount lustre-OST0000 complete [ 3081.712070] LustreError: 157231:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 3081.714161] LustreError: 157231:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 3081.750511] Lustre: server umount lustre-OST0001 complete [ 3085.904664] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3088.458245] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3088.753342] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3093.910033] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3097.046985] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3097.053425] Lustre: lustre-MDT0000: reset Object Index mappings [ 3097.213258] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3098.391222] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3099.270247] Lustre: 160036:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3101.320768] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3101.430892] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3103.131471] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3105.780037] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3106.855547] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:67 to 0x240000400:97) [ 3106.856085] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:67 to 0x280000400:97) [ 3107.560186] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3110.361580] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3111.379806] Lustre: 161880:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3122.144928] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3122.149455] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3122.151101] Lustre: Skipped 1 previous similar message [ 3123.647346] LustreError: 161985:0:(obd_class.h:479:obd_check_dev()) Device 9 not setup [ 3123.649016] LustreError: 161985:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 3123.705785] Lustre: server umount lustre-MDT0000 complete [ 3124.985206] LustreError: 159612:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773237983 with bad export cookie 2627446065088876956 [ 3124.986867] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3124.990882] LustreError: 159612:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 3125.024574] Lustre: server umount lustre-OST0000 complete [ 3126.304960] Lustre: server umount lustre-OST0001 complete [ 3132.491209] Lustre: DEBUG MARKER: == conf-sanity test 155: gap in seq allocation from ofd after restarting ========================================================== 10:06:30 (1773237990) [ 3136.887166] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 3139.617484] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3142.626213] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3144.495822] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3146.496555] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3148.698634] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3148.719659] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3148.798737] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3148.811096] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3148.849794] Lustre: lustre-MDT0000: new disk, initializing [ 3148.870976] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3148.872821] Lustre: Skipped 1 previous similar message [ 3148.878483] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3150.061015] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3152.932415] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3155.002882] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3155.025036] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3155.105848] Lustre: lustre-OST0000: new disk, initializing [ 3155.107426] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3155.109899] Lustre: Skipped 1 previous similar message [ 3156.477516] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 3156.481058] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 3156.489156] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 3156.857751] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3159.744273] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3160.949097] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 3161.011793] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 3161.568142] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 3161.568440] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3161.574008] Lustre: Skipped 1 previous similar message [ 3161.575508] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3166.688294] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3167.661032] LustreError: 167301:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3167.662617] LustreError: 167301:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 3167.689934] Lustre: server umount lustre-OST0000 complete [ 3168.870643] Lustre: server umount lustre-MDT0000 complete [ 3173.334271] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3176.385858] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3176.517279] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3176.518826] Lustre: Skipped 1 previous similar message [ 3177.644594] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3178.508110] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3180.498488] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3182.322101] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3184.993224] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3185.015804] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3185.060050] Lustre: lustre-OST0001: new disk, initializing [ 3185.061762] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3186.815095] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3187.075707] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 3187.078949] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 3187.088964] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 3191.115540] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3192.283638] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3199.128845] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x240000400 to 0x240000401 [ 3199.132030] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x280000400 to 0x280000401 [ 3202.528848] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3202.529458] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3202.532941] Lustre: Skipped 1 previous similar message [ 3207.039063] LustreError: 171416:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 3207.040853] LustreError: 171416:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 3207.095839] Lustre: server umount lustre-MDT0000 complete [ 3208.391426] LustreError: 168603:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773238066 with bad export cookie 2627446065088879126 [ 3208.394077] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3208.395749] LustreError: 168603:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3208.432866] Lustre: server umount lustre-OST0000 complete [ 3209.810202] Lustre: server umount lustre-OST0001 complete [ 3214.782580] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3218.387254] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3218.573185] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3218.575485] Lustre: Skipped 2 previous similar messages [ 3219.971600] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3220.979236] Lustre: 173340:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3223.257776] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3225.293180] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3228.049442] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3229.161073] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000401:4 to 0x240000401:65) [ 3229.166195] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3 to 0x280000401:65) [ 3230.043588] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3233.106110] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3234.261874] Lustre: 175184:0:(mgs_llog.c:1346:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3240.882853] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x240000401 to 0x240000402 [ 3240.886805] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x280000401 to 0x280000402 [ 3243.802957] Lustre: DEBUG MARKER: == conf-sanity test 156: root_fid on export consistent with client mount ========================================================== 10:08:21 (1773238101) [ 3259.872820] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3259.873610] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3259.879261] Lustre: Skipped 1 previous similar message [ 3259.881423] Lustre: Skipped 1 previous similar message [ 3261.436027] LustreError: 175890:0:(obd_class.h:479:obd_check_dev()) Device 9 not setup [ 3261.437922] LustreError: 175890:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 3261.496421] Lustre: server umount lustre-MDT0000 complete [ 3262.815282] LustreError: 172917:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773238121 with bad export cookie 2627446065088884950 [ 3262.818044] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3262.820236] LustreError: 172917:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3277.279106] Lustre: lustre-OST0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 3277.319518] Lustre: server umount lustre-OST0000 complete [ 3284.691675] Lustre: server umount lustre-OST0001 complete [ 3286.770703] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 3289.818993] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3293.356088] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3295.369220] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3297.500407] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3302.314649] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3305.844982] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3305.861587] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3305.932442] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3305.945165] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3305.980632] Lustre: lustre-MDT0000: new disk, initializing [ 3306.001846] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3306.003503] Lustre: Skipped 2 previous similar messages [ 3306.008435] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3307.193812] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3311.400556] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3311.423083] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3312.770891] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 3312.778396] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 3313.492442] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3317.550175] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3317.570245] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3318.986920] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 3319.397699] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3323.868674] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3333.865396] Lustre: DEBUG MARKER: == conf-sanity test 160: MGC updates failnodes from all participants ========================================================== 10:09:51 (1773238191) [ 3334.624197] Lustre: lustre-MDT0000-lwp-OST0000: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3334.624645] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3334.628201] Lustre: Skipped 1 previous similar message [ 3334.631134] Lustre: Skipped 2 previous similar messages [ 3340.733124] LustreError: 181683:0:(obd_class.h:479:obd_check_dev()) Device 17 not setup [ 3340.735258] LustreError: 181683:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 3340.788300] Lustre: server umount lustre-MDT0000 complete [ 3342.005455] LustreError: 178840:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1773238200 with bad export cookie 2627446065088892384 [ 3342.007128] LustreError: MGC192.168.204.138@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3342.010966] LustreError: 178840:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3342.042906] Lustre: server umount lustre-OST0000 complete [ 3343.234907] Lustre: server umount lustre-OST0001 complete [ 3347.706374] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 3350.554930] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3353.506671] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3355.340602] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3357.219638] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3359.747177] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3359.771493] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3359.864555] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3359.867887] Lustre: Skipped 2 previous similar messages [ 3359.876527] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3359.878464] Lustre: Skipped 3 previous similar messages [ 3359.914983] Lustre: lustre-MDT0000: new disk, initializing [ 3359.916291] Lustre: Skipped 2 previous similar messages [ 3359.945371] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3359.947552] Lustre: Skipped 2 previous similar messages [ 3361.209255] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3364.281727] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3366.541404] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3366.569929] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3368.514399] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 3368.517849] Lustre: Skipped 1 previous similar message [ 3368.525480] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 3368.686410] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3371.863874] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3372.611062] Lustre: Mounted lustre-client [ 3372.943231] LustreError: 186139:0:(lov_obd.c:783:lov_cleanup()) lustre-clilov-ffff9d2013531800: lov tgt 0 not cleaned! deathrow=0, lovrc=1 [ 3372.960713] Lustre: Unmounted lustre-client [ 3377.632678] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3377.637304] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3377.639035] Lustre: Skipped 2 previous similar messages [ 3382.028622] Lustre: server umount lustre-OST0000 complete [ 3383.381320] Lustre: server umount lustre-MDT0000 complete [ 3387.112972] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3388.251197] Key type lgssc unregistered [ 3422.175254] LNet: 187215:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3422.177493] LNetError: 187215:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3504.101347] LNet: Removed LNI 192.168.204.138@tcp [ 3504.409111] Key type .llcrypt unregistered [ 3504.410559] Key type ._llcrypt unregistered [ 3509.378582] Key type ._llcrypt registered [ 3509.379647] Key type .llcrypt registered [ 3509.420796] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 3515.753408] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3516.150412] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3516.157045] alg: No test for adler32 (adler32-zlib) [ 3517.009132] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 3517.087674] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 3518.671214] Key type lgssc registered [ 3519.197922] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3522.158900] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3524.073328] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3526.254236] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3526.838411] Lustre: DEBUG MARKER: == conf-sanity test 161: test '-o mgsname' option ======== 10:13:04 (1773238384) [ 3529.048857] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3529.070160] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3529.075902] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3530.173182] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3530.187054] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3530.227380] Lustre: lustre-MDT0000: new disk, initializing [ 3530.255168] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3530.262144] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3531.582248] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3534.578525] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 3536.783035] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3536.813357] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3536.905395] Lustre: lustre-OST0000: new disk, initializing [ 3536.907268] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3536.909633] Lustre: Skipped 1 previous similar message [ 3536.931034] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3538.880153] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_default_debug -1 all [ 3541.900417] Lustre: DEBUG MARKER: oleg438-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 3544.059842] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 3544.062774] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 3544.070045] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 3554.272813] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3554.273058] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 3554.276928] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 3557.102099] LustreError: 191541:0:(obd_class.h:479:obd_check_dev()) Device 12 not setup [ 3557.144777] Lustre: server umount lustre-OST0000 complete [ 3558.395573] LustreError: 191743:0:(obd_class.h:479:obd_check_dev()) Device 13 not setup [ 3558.397595] LustreError: 191743:0:(obd_class.h:479:obd_check_dev()) Skipped 1 previous similar message [ 3558.453613] Lustre: server umount lustre-MDT0000 complete [ 3561.974877] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3563.070223] Key type lgssc unregistered [ 3563.206366] LNet: 192274:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3563.209331] LNetError: 192274:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3563.218307] LNet: Removed LNI 192.168.204.138@tcp [ 3563.512418] Key type .llcrypt unregistered [ 3563.513494] Key type ._llcrypt unregistered [ 3591.773777] Key type ._llcrypt registered [ 3591.775063] Key type .llcrypt registered [ 3591.815817] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3591.912301] Key type .llcrypt unregistered [ 3591.913601] Key type ._llcrypt unregistered [ 3615.052166] Key type ._llcrypt registered [ 3615.053071] Key type .llcrypt registered [ 3615.084159] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3615.168406] Key type .llcrypt unregistered [ 3615.169443] Key type ._llcrypt unregistered [ 3623.953503] Key type ._llcrypt registered [ 3623.954521] Key type .llcrypt registered [ 3623.990332] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3624.080163] Key type .llcrypt unregistered [ 3624.081205] Key type ._llcrypt unregistered [ 3633.880397] Key type ._llcrypt registered [ 3633.881337] Key type .llcrypt registered [ 3633.917562] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3634.014374] Key type .llcrypt unregistered [ 3634.015672] Key type ._llcrypt unregistered [ 3657.734453] Key type ._llcrypt registered [ 3657.735277] Key type .llcrypt registered [ 3657.764141] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3657.846571] Key type .llcrypt unregistered [ 3657.847844] Key type ._llcrypt unregistered [ 3667.411462] Key type ._llcrypt registered [ 3667.412642] Key type .llcrypt registered [ 3667.451794] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3667.548373] Key type .llcrypt unregistered [ 3667.549804] Key type ._llcrypt unregistered [ 3677.318105] Key type ._llcrypt registered [ 3677.319439] Key type .llcrypt registered [ 3677.357251] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3677.457263] Key type .llcrypt unregistered [ 3677.458283] Key type ._llcrypt unregistered [ 3687.110366] Key type ._llcrypt registered [ 3687.111381] Key type .llcrypt registered [ 3687.149387] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3687.257507] Key type .llcrypt unregistered [ 3687.258950] Key type ._llcrypt unregistered [ 3696.973219] Key type ._llcrypt registered [ 3696.974797] Key type .llcrypt registered [ 3697.012815] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3697.102212] Key type .llcrypt unregistered [ 3697.103182] Key type ._llcrypt unregistered [ 3706.656242] Key type ._llcrypt registered [ 3706.657234] Key type .llcrypt registered [ 3706.695153] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3706.795426] Key type .llcrypt unregistered [ 3706.796629] Key type ._llcrypt unregistered [ 3724.347105] Key type ._llcrypt registered [ 3724.348115] Key type .llcrypt registered [ 3724.384875] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3724.484309] Key type .llcrypt unregistered [ 3724.485524] Key type ._llcrypt unregistered [ 3734.116296] Key type ._llcrypt registered [ 3734.117223] Key type .llcrypt registered [ 3734.151629] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3734.256188] Key type .llcrypt unregistered [ 3734.257309] Key type ._llcrypt unregistered [ 3743.763121] Key type ._llcrypt registered [ 3743.764178] Key type .llcrypt registered [ 3743.800877] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3743.895214] Key type .llcrypt unregistered [ 3743.896329] Key type ._llcrypt unregistered [ 3760.434162] Key type ._llcrypt registered [ 3760.435804] Key type .llcrypt registered [ 3760.476903] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing set_hostid [ 3766.469715] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing load_modules_local [ 3766.800359] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3766.838254] alg: No test for adler32 (adler32-zlib) [ 3767.689521] Lustre: Lustre: Build Version: 2.16.59_50_g7c1f86b [ 3767.770267] LNet: Added LNI 192.168.204.138@tcp [8/256/0/180] [ 3769.351179] Key type lgssc registered [ 3769.717073] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3772.699717] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3774.767088] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3776.946030] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3777.499819] Lustre: DEBUG MARKER: == conf-sanity test complete, duration 3559 sec ========== 10:17:15 (1773238635) [ 3778.050943] Lustre: DEBUG MARKER: === conf-sanity: start cleanup 10:17:15 (1773238635) === [ 3779.117818] Lustre: DEBUG MARKER: === conf-sanity: finish cleanup 10:17:16 (1773238636) === [ 3789.615973] Lustre: DEBUG MARKER: oleg438-server.virtnet: executing unload_modules_local [ 3790.646167] Key type lgssc unregistered [ 3790.776386] LNet: 209650:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3790.778593] LNetError: 209650:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3790.787269] LNet: Removed LNI 192.168.204.138@tcp [ 3791.070363] Key type .llcrypt unregistered [ 3791.071418] Key type ._llcrypt unregistered