[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-22) (GCC)) #7 SMP Sat Jan 18 21:01:29 EST 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 3.0.0 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 1080665544 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f53f0-0x000f53ff] [ 0.000000] RAMDISK: [mem 0xbcbe3000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F5200 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE1D87 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE1C23 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 001BE3 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE1C97 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE1D27 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE1D5F 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe1c23-0xbffe1c96] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe1c22] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe1c97-0xbffe1d26] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe1d27-0xbffe1d5e] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe1d5f-0xbffe1d86] [ 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 2480MB 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 513 pages/cpu s2064384 r8192 d28672 u4194304 [ 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: 2818960K/4306352K available (20483K kernel code, 12066K rwdata, 7356K rodata, 4680K init, 23504K bss, 542480K 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 41388 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] 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+0x616/0x99a with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 0.001000] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 0.001000] ... MAX_LOCK_DEPTH: 48 [ 0.001000] ... MAX_LOCKDEP_KEYS: 8192 [ 0.001000] ... CLASSHASH_SIZE: 4096 [ 0.001000] ... MAX_LOCKDEP_ENTRIES: 32768 [ 0.001000] ... MAX_LOCKDEP_CHAINS: 65536 [ 0.001000] ... CHAINHASH_SIZE: 32768 [ 0.001000] memory used by lock dependency info: 4149 kB [ 0.001000] per task-struct memory footprint: 2688 bytes [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001048] APIC: Switch to symmetric I/O mode setup [ 0.003000] x2apic enabled [ 0.004014] Switched APIC routing to physical x2apic. [ 0.005130] kvm-guest: setup PV IPIs [ 0.012000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.012000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.012166] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.014065] pid_max: default: 32768 minimum: 301 [ 0.016578] LSM: Security Framework initializing [ 0.019073] Yama: becoming mindful. [ 0.021029] SELinux: Initializing. [ 0.025130] *** VALIDATE selinux *** [ 0.048263] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.054224] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.056631] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.058150] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.059366] *** VALIDATE tmpfs *** [ 0.063519] *** VALIDATE proc *** [ 0.067497] *** VALIDATE cgroup *** [ 0.068030] *** VALIDATE cgroup2 *** [ 0.070030] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.073039] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.075021] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.076052] Spectre V2 : User space: Vulnerable [ 0.077047] Speculative Store Bypass: Vulnerable [ 0.082000] debug: unmapping init [mem 0xffffffff8ef03000-0xffffffff8ef0afff] [ 0.084313] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.089932] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.090058] ... version: 2 [ 0.091027] ... bit width: 48 [ 0.092010] ... generic registers: 4 [ 0.093027] ... value mask: 0000ffffffffffff [ 0.094037] ... max period: 00007fffffffffff [ 0.095027] ... fixed-purpose events: 3 [ 0.096019] ... event mask: 000000070000000f [ 0.098041] rcu: Hierarchical SRCU implementation. [ 0.104128] smp: Bringing up secondary CPUs ... [ 0.107838] x86: Booting SMP configuration: [ 0.108035] .... node #0, CPUs: #1 [ 0.118034] #2 [ 0.129540] #3 [ 0.135041] smp: Brought up 1 node, 4 CPUs [ 0.136056] smpboot: Max logical packages: 1 [ 0.137025] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.158000] node 0 deferred pages initialised in 14ms [ 0.160200] pgdatinit0 (35) used greatest stack depth: 14528 bytes left [ 0.165478] devtmpfs: initialized [ 0.166993] x86/mm: Memory block size: 128MB [ 0.181585] gcov: version magic: 0x41383552 [ 0.191218] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.194259] futex hash table entries: 1024 (order: 5, 131072 bytes, vmalloc) [ 0.202000] pinctrl core: initialized pinctrl subsystem [ 0.208000] [ 0.208000] ************************************************************* [ 0.213029] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.221024] ** ** [ 0.229049] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.233031] ** ** [ 0.238034] ** This means that this kernel is built to expose internal ** [ 0.250044] ** IOMMU data structures, which may compromise security on ** [ 0.259066] ** your system. ** [ 0.262023] ** ** [ 0.272037] ** If you see this message and you are not debugging the ** [ 0.279039] ** kernel, report this immediately to your vendor! ** [ 0.281019] ** ** [ 0.282000] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.284025] ************************************************************* [ 0.296418] NET: Registered protocol family 16 [ 0.300915] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.301147] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.302141] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.312024] cpuidle: using governor menu [ 0.317770] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.321576] PCI: Using configuration type 1 for base access [ 0.323163] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.394982] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.395000] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.402000] cryptd: max_cpu_qlen set to 1000 [ 0.402000] ACPI: Added _OSI(Module Device) [ 0.402000] ACPI: Added _OSI(Processor Device) [ 0.402000] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.405035] ACPI: Added _OSI(Processor Aggregator Device) [ 0.446863] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.459000] ACPI: Interpreter enabled [ 0.459000] ACPI: PM: (supports S0 S3 S4 S5) [ 0.459000] ACPI: Using IOAPIC for interrupt routing [ 0.462299] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.469411] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.552728] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.554092] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.556022] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.560562] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.574775] acpiphp: Slot [2] registered [ 0.577413] acpiphp: Slot [5] registered [ 0.580021] acpiphp: Slot [6] registered [ 0.582297] acpiphp: Slot [7] registered [ 0.583698] acpiphp: Slot [8] registered [ 0.585536] acpiphp: Slot [9] registered [ 0.588000] acpiphp: Slot [10] registered [ 0.589613] acpiphp: Slot [3] registered [ 0.598524] acpiphp: Slot [4] registered [ 0.601106] acpiphp: Slot [11] registered [ 0.605473] acpiphp: Slot [12] registered [ 0.607308] acpiphp: Slot [13] registered [ 0.610333] acpiphp: Slot [14] registered [ 0.613426] acpiphp: Slot [15] registered [ 0.614000] acpiphp: Slot [16] registered [ 0.615197] acpiphp: Slot [17] registered [ 0.616345] acpiphp: Slot [18] registered [ 0.618365] acpiphp: Slot [19] registered [ 0.620272] acpiphp: Slot [20] registered [ 0.621291] acpiphp: Slot [21] registered [ 0.624265] acpiphp: Slot [22] registered [ 0.625000] acpiphp: Slot [23] registered [ 0.629536] acpiphp: Slot [24] registered [ 0.632732] acpiphp: Slot [25] registered [ 0.636000] acpiphp: Slot [26] registered [ 0.639128] acpiphp: Slot [27] registered [ 0.645194] acpiphp: Slot [28] registered [ 0.650512] acpiphp: Slot [29] registered [ 0.659442] acpiphp: Slot [30] registered [ 0.661483] acpiphp: Slot [31] registered [ 0.669408] PCI host bridge to bus 0000:00 [ 0.671121] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.673082] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.677102] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.680057] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.683079] pci_bus 0000:00: root bus resource [mem 0x380000000000-0x38007fffffff window] [ 0.687059] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.688413] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.693000] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.703266] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.714020] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.715000] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.719035] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.721026] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.726051] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.730942] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.739198] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.741060] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.746259] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.750900] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.764015] pci 0000:00:02.0: reg 0x20: [mem 0x380000000000-0x380000003fff 64bit pref] [ 0.771028] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.808438] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.816035] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.823022] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.848028] pci 0000:00:05.0: reg 0x20: [mem 0x380000004000-0x380000007fff 64bit pref] [ 0.918173] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.929044] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.943054] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.975023] pci 0000:00:06.0: reg 0x20: [mem 0x380000008000-0x38000000bfff 64bit pref] [ 1.006274] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 1.015046] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 1.016000] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 1.042022] pci 0000:00:07.0: reg 0x20: [mem 0x38000000c000-0x38000000ffff 64bit pref] [ 1.088000] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 1.094040] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 1.101000] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 1.112000] pci 0000:00:08.0: reg 0x20: [mem 0x380000010000-0x380000013fff 64bit pref] [ 1.231000] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 1.257000] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 1.266020] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 1.311030] pci 0000:00:09.0: reg 0x20: [mem 0x380000014000-0x380000017fff 64bit pref] [ 1.368685] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 1.382021] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 1.390021] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 1.412020] pci 0000:00:0a.0: reg 0x20: [mem 0x380000018000-0x38000001bfff 64bit pref] [ 1.450757] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 1.456262] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 1.462000] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 1.466568] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 1.470186] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 1.483018] iommu: Default domain type: Passthrough [ 1.488058] SCSI subsystem initialized [ 1.490568] ACPI: bus type USB registered [ 1.492794] usbcore: registered new interface driver usbfs [ 1.493000] usbcore: registered new interface driver hub [ 1.498229] usbcore: registered new device driver usb [ 1.501704] pps_core: LinuxPPS API ver. 1 registered [ 1.502012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 1.503121] PTP clock support registered [ 1.506395] EDAC MC: Ver: 3.0.0 [ 1.511497] PCI: Using ACPI for IRQ routing [ 1.515328] NetLabel: Initializing [ 1.517024] NetLabel: domain hash size = 128 [ 1.518017] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 1.520410] NetLabel: unlabeled traffic allowed by default [ 1.532567] vgaarb: loaded [ 1.536418] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 1.548061] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 1.599033] clocksource: Switched to clocksource kvm-clock [ 2.642270] VFS: Disk quotas dquot_6.6.0 [ 2.648000] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 2.650664] *** VALIDATE ramfs *** [ 2.651916] *** VALIDATE hugetlbfs *** [ 2.653946] pnp: PnP ACPI init [ 2.663657] pnp: PnP ACPI: found 6 devices [ 2.726233] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 2.733059] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 2.738664] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 2.743090] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 2.747371] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 2.751666] pci_bus 0000:00: resource 8 [mem 0x380000000000-0x38007fffffff window] [ 2.759291] NET: Registered protocol family 2 [ 2.766626] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 2.776574] tcp_listen_portaddr_hash hash table entries: 4096 (order: 6, 360448 bytes, vmalloc) [ 2.782787] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 2.798589] TCP bind hash table entries: 65536 (order: 10, 5242880 bytes, vmalloc) [ 2.814349] TCP: Hash tables configured (established 65536 bind 65536) [ 2.822951] MPTCP token hash table entries: 8192 (order: 7, 786432 bytes, vmalloc) [ 2.832418] UDP hash table entries: 4096 (order: 7, 786432 bytes, vmalloc) [ 2.839637] UDP-Lite hash table entries: 4096 (order: 7, 786432 bytes, vmalloc) [ 2.848333] NET: Registered protocol family 1 [ 2.861103] RPC: Registered named UNIX socket transport module. [ 2.866151] RPC: Registered udp transport module. [ 2.869470] RPC: Registered tcp transport module. [ 2.873146] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 2.878537] NET: Registered protocol family 44 [ 2.880400] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 2.884993] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 2.891152] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 2.896032] PCI: CLS 0 bytes, default 64 [ 2.900749] Unpacking initramfs... [ 8.501030] hrtimer: interrupt took 8014779 ns [ 10.132701] debug: unmapping init [mem 0xffff8f7d7cbe3000-0xffff8f7d7ffbffff] [ 10.156775] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 10.168599] software IO TLB: mapped [mem 0x00000000b8be3000-0x00000000bcbe3000] (64MB) [ 10.184291] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 10.248309] cryptomgr_test (64) used greatest stack depth: 14248 bytes left [ 10.263696] cryptomgr_test (66) used greatest stack depth: 14008 bytes left [ 13.964334] Initialise system trusted keyrings [ 13.966176] Key type blacklist registered [ 13.986667] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 14.256333] zbud: loaded [ 14.320559] *** VALIDATE nfs *** [ 14.329848] *** VALIDATE nfs4 *** [ 14.347134] pstore: using deflate compression [ 14.370102] Platform Keyring initialized [ 14.541064] cryptomgr_test (83) used greatest stack depth: 13976 bytes left [ 14.571570] cryptomgr_test (85) used greatest stack depth: 13800 bytes left [ 14.658374] cryptomgr_test (93) used greatest stack depth: 13640 bytes left [ 14.759185] cryptomgr_test (102) used greatest stack depth: 13560 bytes left [ 15.110491] NET: Registered protocol family 38 [ 15.112552] Key type asymmetric registered [ 15.118246] Asymmetric key parser 'x509' registered [ 15.124721] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 15.138339] io scheduler mq-deadline registered [ 15.142288] io scheduler kyber registered [ 15.150703] io scheduler bfq registered [ 15.154666] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 15.173378] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 15.193860] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 15.221218] ACPI: Power Button [PWRF] [ 20.915414] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 26.138581] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 39.317871] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 45.351951] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 57.944248] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 58.069680] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 58.191312] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 58.233133] Non-volatile memory driver v1.3 [ 58.246416] Linux agpgart interface v0.103 [ 58.878400] virtio_blk virtio1: [vda] 131896 512-byte logical blocks (67.5 MB/64.4 MiB) [ 58.899525] vda: detected capacity change from 0 to 67530752 [ 59.041392] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 59.049545] vdb: detected capacity change from 0 to 1073741824 [ 59.182353] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 59.185387] vdc: detected capacity change from 0 to 2621440000 [ 59.309157] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 59.327316] vdd: detected capacity change from 0 to 2621440000 [ 59.412412] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 59.415237] vde: detected capacity change from 0 to 4294967296 [ 59.502064] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 59.524094] vdf: detected capacity change from 0 to 4294967296 [ 59.568779] libphy: Fixed MDIO Bus: probed [ 59.632462] usbcore: registered new interface driver usbserial_generic [ 59.645985] usbserial: USB Serial support registered for generic [ 59.648652] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 59.660378] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 59.667890] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 59.673254] mousedev: PS/2 mouse device common for all mice [ 59.677678] rtc_cmos 00:05: RTC can wake from S4 [ 59.679879] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 59.694779] rtc_cmos 00:05: registered as rtc0 [ 59.696635] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 59.704884] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 59.708306] intel_pstate: CPU model not supported [ 59.725434] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 59.736402] hid: raw HID events driver (C) Jiri Kosina [ 59.739252] usbcore: registered new interface driver usbhid [ 59.741947] usbhid: USB HID core driver [ 59.744958] drop_monitor: Initializing network drop monitor service [ 59.747907] Initializing XFRM netlink socket [ 59.754448] NET: Registered protocol family 10 [ 59.764292] Segment Routing with IPv6 [ 59.766089] NET: Registered protocol family 17 [ 59.768700] mpls_gso: MPLS GSO support [ 59.778849] RAS: Correctable Errors collector initialized. [ 59.781234] AVX version of gcm_enc/dec engaged. [ 59.783820] AES CTR mode by8 optimization enabled [ 60.180203] sched_clock: Marking stable (60180146716, 0)->(62691012470, -2510865754) [ 60.184924] registered taskstats version 1 [ 60.206594] Loading compiled-in X.509 certificates [ 60.212524] zswap: loaded using pool lzo/zbud [ 60.386565] Key type big_key registered [ 60.463392] Key type encrypted registered [ 60.465140] ima: No TPM chip found, activating TPM-bypass! [ 60.482227] ima: Allocated hash algorithm: sha1 [ 60.483580] ima: No architecture policies found [ 60.485529] evm: Initialising EVM extended attributes: [ 60.487425] evm: security.selinux [ 60.488683] evm: security.ima [ 60.489813] evm: security.capability [ 60.514907] evm: HMAC attrs: 0x1 [ 60.531595] rtc_cmos 00:05: setting system clock to 2025-04-01 07:34:12 UTC (1743492852) [ 60.672169] debug: unmapping init [mem 0xffffffff90403000-0xffffffff905fffff] [ 60.685070] debug: unmapping init [mem 0xffffffff8ea71000-0xffffffff8ef02fff] [ 60.699898] Write protecting the kernel read-only data: 30720k [ 60.725118] debug: unmapping init [mem 0xffffffff8d003000-0xffffffff8d1fffff] [ 60.738631] debug: unmapping init [mem 0xffffffff8d92f000-0xffffffff8d9fffff] [ 61.225991] systemd[1]: systemd 239 (239-82.el8_10.3) 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) [ 61.293643] systemd[1]: Detected virtualization kvm. [ 61.308026] systemd[1]: Detected architecture x86-64. [ 61.309836] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 61.458326] systemd[1]: No hostname configured. [ 61.468614] systemd[1]: Set hostname to . [ 61.484794] random: systemd: uninitialized urandom read (16 bytes read) [ 61.541087] systemd[1]: Initializing machine ID from random generator. [ 62.838356] random: systemd: uninitialized urandom read (16 bytes read) [ 62.840795] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 62.864526] random: systemd: uninitialized urandom read (16 bytes read) [ 62.874916] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 62.908507] random: systemd: uninitialized urandom read (16 bytes read) [ 62.915378] systemd[1]: Reached target Local Encrypted Volumes. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Paths. [ OK ] Reached target Initrd Root Device. [ OK ] Reached target Swap. [ OK ] Reached target Local File Systems. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Timers. [ OK ] Listening on Journal Socket. Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on Journal Socket (/dev/log). Starting Journal Service... Starting Create Volatile Files and Directories... [ OK ] Listening on udev Control Socket. [ OK ] Reached target Sockets. Starting Apply Kernel Variables... [ 63.829033] systemd-cgroups (247) used greatest stack depth: 13344 bytes left [ 63.960922] systemd-tmpfile (246) used greatest stack depth: 13336 bytes left [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 68.230194] device-mapper: uevent: version 1.0.3 [ 68.235285] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ 77.729918] virtio_net virtio0 ens2: renamed from eth0 [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 78.853652] scsi host0: ata_piix [ 79.385475] random: fast init done [ 80.078514] scsi host1: ata_piix [ 80.080584] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 80.083174] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 85.388518] random: crng init done [ 85.410977] random: 6 urandom warning(s) missed due to ratelimiting [ 87.755966] systemd-udevd (438) used greatest stack depth: 13048 bytes left [ 87.777435] systemd-udevd (448) used greatest stack depth: 12664 bytes left [ 88.431157] ip (530) used greatest stack depth: 11496 bytes left [ 95.190123] dracut-initqueue[592]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 102.245096] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ 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 udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Local File Systems. [ OK ] Stopped Apply Kernel Variables. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 115.694291] printk: systemd: 26 output lines suppressed due to ratelimiting [ 118.404027] SELinux: Disabled at runtime. [ 118.856078] systemd[1]: systemd 239 (239-82.el8_10.3) 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) [ 118.921640] systemd[1]: Detected virtualization kvm. [ 118.923796] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 124.721551] systemd[1]: initrd-switch-root.service: Succeeded. [ 124.812947] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 124.866632] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 124.870558] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 124.873945] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 124.972229] systemd[1]: Starting Journal Service... Starting Journal Service... [ 125.040055] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 125.086275] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 125.143608] systemd[1]: Reached target rpc_pipefs.target. [ OK ] Reached target rpc_pipefs.target. [ 125.238496] systemd[1]: Listening on RPCbind Server Activation Socket. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Stopped target Switch Root. Mounting Huge Pages File System... Mounting Kernel Debug File System... [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on Process Core Dump Socket. Starting Remount Root and Kernel File Systems... Mounting POSIX Message Queue File System... Activating swap /dev/disk/by-label/SWAP... [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Stopped target Initrd Root File System. [ OK ] Created slice system-sshd\x2dkeygen.slice. Starting Create list of required st…ce nodes for the current kernel... [ OK [[ 126.838860] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS 0m] Created slice system-getty.slice. [ OK ] Reached target RPC Port Mapper. [ OK ] Stopped target Initrd File Systems. [ OK ] Listening on udev Kernel Socket. Starting udev Coldplug all Devices... [ OK ] Created slice User and Session Slice. Starting Apply Kernel Variables... [ OK ] Reached target Slices. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. [ OK ] Started Journal Service. [ OK ] Mounted Huge Pages File System. [ OK ] Mounted Kernel Debug File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ 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 Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... Starting udev Kernel Device Manager... [ OK ] Started udev Coldplug all Devices. [ OK ] Mounted /mnt. [ 133.172771] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 138.073776] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 139.906132] input: PC Speaker as /devices/platform/pcspkr/input/input5 [* ] A start job is running for Configur…only root support (17s / no limit) [** ] A start job is running for Configur…only root support (18s / no limit) [*** ] A start job is running for Configur…only root support (18s / no limit) [ *** ] A start job is running for Configur…only root support (19s / no limit)[ 143.370382] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ *** ] A start job is running for Configur…only root support (19s / no limit) [ ***] A start job is running for Configur…only root support (20s / no limit)[ 144.764515] EDAC sbridge: Ver: 1.1.2 [ **] A start job is running for Configur…only root support (22s / no limit) [ *] A start job is running for Configur…only root support (22s / no limit) [ **] A start job is running for Configur…only root support (23s / no limit) [ ***] A start job is running for Configur…only root support (25s / no limit) [ *** ] A start job is running for Configur…only root support (31s / no limit) [ *** ] A start job is running for Configur…only root support (32s / no limit) [*** ] A start job is running for Configur…only root support (32s / no limit) [** ] A start job is running for Configur…only root support (33s / no limit) [* ] A start job is running for Configur…only root support (33s / no limit) [** ] A start job is running for Configur…only root support (34s / no limit) [*** ] A start job is running for Configur…only root support (34s / no limit) [ *** ] A start job is running for Configur…only root support (35s / no limit) [ *** ] A start job is running for Configur…only root support (35s / no limit) [ ***] A start job is running for Configur…only root support (36s / no limit) [ **] A start job is running for Configur…only root support (36s / no limit) [ *] A start job is running for Configur…only root support (37s / no limit) [ **] A start job is running for Configur…only root support (37s / no limit) [ ***] A start job is running for Configur…only root support (38s / no limit) [ *** ] A start job is running for Configur…only root support (38s / no limit) [ *** ] A start job is running for Configur…only root support (39s / no limit) [*** ] A start job is running for Configur…only root support (39s / no limit) [** ] A start job is running for Configur…only root support (40s / no limit) [* ] A start job is running for Configur…only root support (40s / no limit) [** ] A start job is running for Configur…only root support (41s / no limit) [*** ] A start job is running for Configur…only root support (41s / no limit) [ *** ] A start job is running for Configur…only root support (44s / no limit) [ *** ] A start job is running for Configur…only root support (44s / no limit)[ 168.748909] Key type dns_resolver registered [ ***] A start job is running for Configur…only root support (45s / no limit) [ **] A start job is running for Configur…only root support (45s / no limit) [ *] A start job is running for Configur…only root support (46s / no limit) [ **] A start job is running for Configur…only root support (46s / no limit)[ 170.763528] NFS: Registering the id_resolver key type [ 170.827843] Key type id_resolver registered [ 170.845975] Key type id_legacy registered [ ***] A start job is running for Configur…only root support (47s / no limit) [ *** ] A start job is running for Configur…only root support (47s / no limit) [ *** ] A start job is running for Configur…only root support (48s / no limit)[ 172.336118] mount.nfs (978) used greatest stack depth: 10760 bytes left [*** ] A start job is running for Configur…only root support (48s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Rebuild Dynamic Linker Cache... Starting Mark the need to relabel after reboot... Starting Load/Save Random Seed... Starting Create Volatile Files and Directories... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Reached target sshd-keygen.target. [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... [ OK ] Started Login Service. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... Starting Hostname Service... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Reached target Login Prompts. [ OK ] Started OpenSSH server daemon. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg605-server login: [ 294.756905] libcfs: loading out-of-tree module taints kernel. [ 294.812798] Key type ._llcrypt registered [ 294.816425] Key type .llcrypt registered [ 295.102251] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_hostid [ 335.369783] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 340.269784] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 340.328348] alg: No test for adler32 (adler32-zlib) [ 342.795951] Lustre: Lustre: Build Version: 2.16.52_73_g6bb624e [ 344.680059] LNet: Added LNI 192.168.206.105@tcp [8/256/0/180] [ 344.686996] LNet: Accept secure, port 988 [ 346.800463] Key type lgssc registered [ 350.809856] Lustre: Echo OBD driver; http://www.lustre.org/ [ 385.709968] ZFS: Loaded module v2.3.0-1, ZFS pool version 5000, ZFS filesystem version 5 [ 385.741757] modprobe (4354) used greatest stack depth: 5648 bytes left [ 392.825060] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 416.757630] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 432.711402] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 450.295935] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 489.497548] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 524.322832] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 524.519936] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 524.546919] ------------[ cut here ]------------ [ 524.548880] DEBUG_LOCKS_WARN_ON(!lockdep_enabled()) [ 524.548906] WARNING: CPU: 1 PID: 6543 at kernel/locking/lockdep.c:4713 lockdep_init_map_type+0x29d/0x410 [ 524.554945] Modules linked in: zfs(O) spl(O) lustre(O) osp(O) ofd(O) lod(O) mdt(O) mdd(O) mgs(O) osd_ldiskfs(O) ldiskfs(O) lquota(O) lfsck(O) obdecho(O) mgc(O) mdc(O) lov(O) osc(O) lmv(O) fid(O) fld(O) ptlrpc_gss(O) ptlrpc(O) obdclass(O) ksocklnd(O) lnet(O) libcfs(O) dm_flakey rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver intel_rapl_msr intel_rapl_common sb_edac rapl pcspkr i2c_piix4 squashfs crct10dif_pclmul ata_generic crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw ata_piix libata dm_mirror dm_region_hash dm_log dm_mod sha512_ssse3 sha512_generic [ 524.571016] CPU: 1 PID: 6543 Comm: mount.lustre Kdump: loaded Tainted: G O -------- - - 4.18.0rh8.10-debug #7 [ 524.573806] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-1.fc39 04/01/2014 [ 524.575918] RIP: 0010:lockdep_init_map_type+0x29d/0x410 [ 524.577746] Code: c0 0f 85 db fe ff ff 48 c7 c6 66 64 79 8d 48 c7 c7 a7 4e 77 8d 48 83 05 f0 df 25 03 01 e8 27 14 f5 ff 48 83 05 eb df 25 03 01 <0f> 0b 48 83 05 e9 df 25 03 01 48 83 05 e9 df 25 03 01 e9 a1 fe ff [ 524.583903] RSP: 0018:ffffabf9c2833748 EFLAGS: 00010202 [ 524.585794] RAX: 0000000000000000 RBX: ffff8f7df65fb9c0 RCX: 0000000000000001 [ 524.588335] RDX: 0000000000000001 RSI: 00000000ffff7fff RDI: ffff8f7e017de800 [ 524.590718] RBP: ffffffffc149a7c0 R08: 0000000000000000 R09: c0000000ffff7fff [ 524.593208] R10: 0000000000000001 R11: ffffabf9c2833538 R12: 0000000000000002 [ 524.597242] R13: ffff8f7dd9584000 R14: 0000000000000000 R15: 0000000000000001 [ 524.599400] FS: 00007ffaaeac8b40(0000) GS:ffff8f7e01600000(0000) knlGS:0000000000000000 [ 524.602331] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 524.604332] CR2: 000055c505e84000 CR3: 00000001075b1001 CR4: 0000000000170ee0 [ 524.606805] Call Trace: [ 524.607454] ? show_regs.cold.9+0x22/0x2f [ 524.608503] ? __warn+0xc8/0x150 [ 524.609268] ? lockdep_init_map_type+0x29d/0x410 [ 524.610312] ? report_bug+0x113/0x140 [ 524.611376] ? do_error_trap+0xb6/0x130 [ 524.612558] ? do_invalid_op+0x46/0x60 [ 524.613743] ? lockdep_init_map_type+0x29d/0x410 [ 524.615108] ? invalid_op+0x14/0x20 [ 524.616480] ? lockdep_init_map_type+0x29d/0x410 [ 524.618576] ? lockdep_init_map_type+0x295/0x410 [ 524.620327] ldiskfs_enable_quotas+0x1b9/0x4a0 [ldiskfs] [ 524.622236] ldiskfs_fill_super+0x3a56/0x43c0 [ldiskfs] [ 524.624416] ? ldiskfs_calculate_overhead+0x670/0x670 [ldiskfs] [ 524.626693] ? mount_bdev+0x226/0x270 [ 524.628090] mount_bdev+0x226/0x270 [ 524.629471] ldiskfs_mount+0x19/0x30 [ldiskfs] [ 524.631189] legacy_get_tree+0x35/0x90 [ 524.632494] vfs_get_tree+0x2a/0x140 [ 524.633857] fc_mount+0x16/0x60 [ 524.635212] vfs_kern_mount+0x91/0x100 [ 524.636532] osd_mount+0x5c4/0x1080 [osd_ldiskfs] [ 524.638181] osd_device_init0+0x2e1/0xc20 [osd_ldiskfs] [ 524.639879] osd_device_alloc+0x22a/0x290 [osd_ldiskfs] [ 524.641953] obd_setup+0x196/0x430 [obdclass] [ 524.646821] class_setup+0x6f5/0x9f0 [obdclass] [ 524.651498] class_process_config+0x1658/0x2b60 [obdclass] [ 524.659705] do_lcfg+0x376/0x740 [obdclass] [ 524.664153] lustre_start_simple+0x8f/0x220 [obdclass] [ 524.669285] osd_start+0x6aa/0xb60 [ptlrpc] [ 524.672916] ? server_name2index+0x79/0xe0 [obdclass] [ 524.679476] ? lsi_prepare+0x2e7/0x690 [ptlrpc] [ 524.683583] server_fill_super+0x99/0x1190 [ptlrpc] [ 524.687869] ? obd_zombie_barrier+0x63/0x120 [obdclass] [ 524.693302] ? debug_mutex_init+0x43/0x60 [ 524.697148] lustre_fill_super+0x4a6/0x5e0 [lustre] [ 524.703766] ? lustre_mount+0x30/0x30 [lustre] [ 524.705968] mount_nodev+0x56/0xf0 [ 524.707828] lustre_mount+0x1c/0x30 [lustre] [ 524.716888] legacy_get_tree+0x35/0x90 [ 524.720752] vfs_get_tree+0x2a/0x140 [ 524.723945] do_mount+0xd84/0x1190 [ 524.728461] ksys_mount+0x11d/0x150 [ 524.732774] __x64_sys_mount+0x29/0x40 [ 524.736344] do_syscall_64+0xc1/0x450 [ 524.737770] entry_SYSCALL_64_after_hwframe+0x49/0xae [ 524.739922] RIP: 0033:0x7ffaaabfcdbe [ 524.741404] Code: 48 8b 0d cd 60 39 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 9a 60 39 00 f7 d8 64 89 01 48 [ 524.748559] RSP: 002b:00007ffe61104e68 EFLAGS: 00000286 ORIG_RAX: 00000000000000a5 [ 524.751539] RAX: ffffffffffffffda RBX: 0000000000430cf6 RCX: 00007ffaaabfcdbe [ 524.754260] RDX: 0000000000430cf6 RSI: 00007ffe6110b510 RDI: 0000000000921940 [ 524.757319] RBP: 00007ffe6110b510 R08: 0000000000921960 R09: 0000000000921010 [ 524.759964] R10: 0000000001000000 R11: 0000000000000286 R12: 0000000000000000 [ 524.762646] R13: 0000000000654920 R14: 00000000fffffff5 R15: 00000000fffffff5 [ 524.764977] ---[ end trace fe1ac171c3d4b4bf ]--- [ 524.773973] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 526.474126] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall in log lustre-MDT0000 [ 526.592585] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 526.671034] Lustre: lustre-MDT0000: new disk, initializing [ 526.895449] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 526.961220] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 533.852454] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 554.891390] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 555.066106] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 555.387885] Lustre: Modifying parameter lustre-MDT0001.mdt.identity_upcall in log lustre-MDT0001 [ 555.413814] Lustre: 7477:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 555.447700] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 555.450705] Lustre: Skipped 1 previous similar message [ 555.558548] Lustre: lustre-MDT0001: new disk, initializing [ 555.721664] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 555.776795] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 555.791629] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 562.513393] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 569.774528] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 585.413884] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 585.610413] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 586.216729] Lustre: 8436:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 586.282884] Lustre: lustre-OST0000: new disk, initializing [ 586.293977] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 586.472967] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 592.561277] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 592.577052] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 592.756203] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 596.057549] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 616.667543] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 616.832562] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 617.110290] Lustre: 9452:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 617.155519] Lustre: lustre-OST0001: new disk, initializing [ 617.171168] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 617.345919] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 626.267417] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 626.282831] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 626.561339] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 627.183674] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 645.711884] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 657.699344] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 674.878121] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing check_logdir /tmp/testlogs/ [ 684.880542] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing yml_node [ 701.242950] Lustre: DEBUG MARKER: Client: 2.16.52.73 [ 707.406498] Lustre: DEBUG MARKER: MDS: 2.16.52.73 [ 713.042810] Lustre: DEBUG MARKER: OSS: 2.16.52.73 [ 716.972424] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-scrub ============----- Tue Apr 1 03:45:04 EDT 2025 [ 751.460796] Lustre: DEBUG MARKER: excepting tests: [ 776.207168] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 795.620825] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 795.622389] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 795.652015] Lustre: Skipped 1 previous similar message [ 795.656062] Lustre: Skipped 2 previous similar messages [ 798.526233] Lustre: server umount lustre-MDT0000 complete [ 805.862803] LustreError: 6573:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 805.902176] LustreError: 6573:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 8 previous similar messages [ 810.984250] LustreError: 6573:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 811.003989] LustreError: 6573:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 3 previous similar messages [ 812.905076] LustreError: 8459:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743493604 with bad export cookie 5620834142717951761 [ 812.914723] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 812.919946] LustreError: 8459:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 813.659178] Lustre: server umount lustre-MDT0001 complete [ 832.482746] Lustre: 3689:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743493608/real 1743493608] req@ffff8f7cc2ebe200 x1828185058724864/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743493624 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 832.522507] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 832.538622] Lustre: Skipped 1 previous similar message [ 833.504965] Lustre: 3690:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743493609/real 1743493609] req@ffff8f7cc2eb8bc0 x1828185058725120/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743493625 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 837.664321] Lustre: 3689:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743493613/real 1743493613] req@ffff8f7cc2eb8600 x1828185058725376/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743493629 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 839.894246] Lustre: server umount lustre-OST0000 complete [ 843.872343] Lustre: 3689:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743493619/real 1743493619] req@ffff8f7cc2ebbf80 x1828185058726016/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743493635 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 843.903595] Lustre: 3689:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 848.876492] Lustre: 3691:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743493624/real 1743493624] req@ffff8f7cc2eba880 x1828185058726272/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743493640 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 855.427145] Lustre: server umount lustre-OST0001 complete [ 897.454900] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing unload_modules_local [ 905.291688] Key type lgssc unregistered [ 906.220115] LNet: 14703:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 907.241128] LNet: Removed LNI 192.168.206.105@tcp [ 910.025203] Key type .llcrypt unregistered [ 910.034835] Key type ._llcrypt unregistered [ 954.622063] Key type ._llcrypt registered [ 954.623481] Key type .llcrypt registered [ 954.889324] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_hostid [ 992.018861] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 996.518653] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 996.700359] alg: No test for adler32 (adler32-zlib) [ 998.080484] Lustre: Lustre: Build Version: 2.16.52_73_g6bb624e [ 998.471503] LNet: Added LNI 192.168.206.105@tcp [8/256/0/180] [ 998.484663] LNet: Accept secure, port 988 [ 1000.279234] Key type lgssc registered [ 1002.964775] Lustre: Echo OBD driver; http://www.lustre.org/ [ 1024.191813] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1041.557380] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1056.771758] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1072.606221] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1111.402962] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 1135.155851] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1135.285515] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 1135.322922] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1136.768476] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall in log lustre-MDT0000 [ 1136.811362] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1136.890771] Lustre: lustre-MDT0000: new disk, initializing [ 1137.055356] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1137.101741] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1143.768304] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1166.385223] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1166.496796] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1166.655352] Lustre: Modifying parameter lustre-MDT0001.mdt.identity_upcall in log lustre-MDT0001 [ 1166.693603] Lustre: 20037:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1166.745325] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1166.747957] Lustre: Skipped 1 previous similar message [ 1166.862483] Lustre: lustre-MDT0001: new disk, initializing [ 1167.017541] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1167.091599] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1167.101622] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1173.693741] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1182.093879] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 1199.573148] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1199.825751] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1200.361078] Lustre: 20996:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1200.407986] Lustre: lustre-OST0000: new disk, initializing [ 1200.428622] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1200.598039] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1209.934659] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1209.940128] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1210.134979] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1210.268764] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1232.131431] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 1232.301152] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1232.545625] Lustre: 22011:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1232.589819] Lustre: lustre-OST0001: new disk, initializing [ 1232.596533] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1232.742062] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 1240.165084] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1240.181254] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1240.368638] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1241.646668] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1260.558360] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1272.557119] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 1296.290345] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 03:54:43 (1743494083) === [ 1300.586673] Lustre: DEBUG MARKER: == sanity-scrub test 0: Do not auto trigger OI scrub for non-backup/restore case ========================================================== 03:54:48 (1743494088) [ 1335.374829] Lustre: Failing over lustre-MDT0000 [ 1335.919739] Lustre: server umount lustre-MDT0000 complete [ 1336.287609] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1336.290476] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1337.844184] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1337.854451] Lustre: Skipped 1 previous similar message [ 1342.043881] Lustre: Failing over lustre-MDT0001 [ 1342.045806] LustreError: 19114:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743494134 with bad export cookie 15735431097706004594 [ 1342.066624] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1342.771239] Lustre: server umount lustre-MDT0001 complete [ 1358.239409] Lustre: 16276:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494134/real 1743494134] req@ffff8f7dfc820bc0 x1828185744501248/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494150 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1358.265238] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1358.284852] Lustre: Skipped 1 previous similar message [ 1359.315803] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1364.447339] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494140/real 1743494140] req@ffff8f7dfc820040 x1828185744501504/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494156 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1364.466172] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 2 previous similar messages [ 1367.866503] LustreError: 21014:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1367.881802] LustreError: 21014:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 6 previous similar messages [ 1368.014762] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1368.064301] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1368.927120] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494144/real 1743494144] req@ffff8f7dfc821740 x1828185744501888/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494160 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1369.000309] LustreError: 24022:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1369.028171] LustreError: 24022:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 1 previous similar message [ 1373.087091] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494149/real 1743494149] req@ffff8f7dfc8239c0 x1828185744502016/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494165 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1373.114468] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1374.176795] LustreError: 24022:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1374.209032] LustreError: 24022:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 3 previous similar messages [ 1375.841133] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1377.253785] LustreError: 24236:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1377.262042] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1377.284510] LustreError: 24236:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 2 previous similar messages [ 1382.370363] LustreError: 24024:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1382.408257] LustreError: 24024:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 2 previous similar messages [ 1392.608633] LustreError: 24023:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1392.648438] LustreError: 24023:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 5 previous similar messages [ 1393.160141] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1393.526792] Lustre: 24737:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1393.864369] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1394.086989] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1394.120230] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 1394.226544] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:41 to 0x2c0000400:65) [ 1394.236712] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:42 to 0x280000400:65) [ 1399.287653] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1399.292942] Lustre: Skipped 1 previous similar message [ 1399.320387] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 1399.432831] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 1399.436261] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:42 to 0x2c0000401:65) [ 1401.682708] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1433.289201] Lustre: DEBUG MARKER: == sanity-scrub test 1a: Auto trigger initial OI scrub when server mounts ========================================================== 03:57:00 (1743494220) [ 1472.592409] Lustre: Failing over lustre-MDT0000 [ 1472.987927] Lustre: server umount lustre-MDT0000 complete [ 1476.066375] 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 [ 1476.068986] LustreError: 24875:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1476.071056] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1476.080259] Lustre: Skipped 4 previous similar messages [ 1476.093242] LustreError: 24875:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 3 previous similar messages [ 1479.837517] LustreError: 19113:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743494271 with bad export cookie 15735431097706020918 [ 1479.839452] Lustre: Failing over lustre-MDT0001 [ 1479.848973] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1479.857409] LustreError: 19113:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 7 previous similar messages [ 1480.513339] Lustre: server umount lustre-MDT0001 complete [ 1496.651657] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1497.567161] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494273/real 1743494273] req@ffff8f7cd6e7bf80 x1828185744633088/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494289 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1497.591605] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1497.608598] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1505.409596] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1505.505198] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1506.463175] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494281/real 1743494281] req@ffff8f7cd6e7b9c0 x1828185744633984/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494297 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1506.519344] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 1512.931091] LustreError: 26376:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1512.946080] LustreError: 26376:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 5 previous similar messages [ 1513.141260] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1517.040561] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1517.043885] Lustre: Skipped 2 previous similar messages [ 1528.872586] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1529.208886] Lustre: 27091:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1529.561357] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1529.833723] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:105 to 0x2c0000400:129) [ 1529.837655] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:106 to 0x280000400:129) [ 1534.949032] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1534.953236] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1534.971741] Lustre: Skipped 1 previous similar message [ 1535.025272] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1535.099608] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 1535.100753] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 1537.250235] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1545.940138] Lustre: *** cfs_fail_loc=193, val=0*** [ 1555.156444] Lustre: Failing over lustre-MDT0000 [ 1555.441237] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1555.446215] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1555.459053] Lustre: Skipped 2 previous similar messages [ 1555.638122] Lustre: server umount lustre-MDT0000 complete [ 1570.001204] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1570.397047] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1570.998785] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1571.016820] Lustre: Skipped 1 previous similar message [ 1571.140828] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1576.426039] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1576.438291] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1576.475175] Lustre: Skipped 2 previous similar messages [ 1576.512032] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1576.590179] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 1576.597302] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 1578.640418] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1598.799898] Lustre: DEBUG MARKER: == sanity-scrub test 1b: Trigger OI scrub when MDT mounts for OI files remove/recreate case ========================================================== 03:59:46 (1743494386) [ 1631.732754] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 1665.434343] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 1708.773884] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1716.157514] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 1746.305405] Lustre: *** cfs_fail_loc=198, val=0*** [ 1765.225404] Lustre: Failing over lustre-MDT0000 [ 1765.840744] Lustre: server umount lustre-MDT0000 complete [ 1765.863288] 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 [ 1765.869384] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1765.874821] Lustre: Skipped 3 previous similar messages [ 1765.885836] LustreError: 21013:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1765.910357] LustreError: 21013:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 25 previous similar messages [ 1771.812524] LustreError: 21027:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743494563 with bad export cookie 15735431097706049436 [ 1771.817640] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1771.819415] Lustre: Failing over lustre-MDT0001 [ 1771.829966] LustreError: 21027:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 1772.591914] Lustre: server umount lustre-MDT0001 complete [ 1780.737851] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1788.811721] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1792.352165] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494568/real 1743494568] req@ffff8f7cd5f9ae40 x1828185744853120/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494584 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1792.388611] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 5 previous similar messages [ 1802.834632] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1816.991737] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7cd5f9f340 x1828185744855296/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1817.764146] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1817.831481] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1821.881250] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1821.902961] Lustre: Skipped 3 previous similar messages [ 1825.094467] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1840.760725] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1841.085579] Lustre: 33548:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1841.334669] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1841.739370] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 1841.757522] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 1846.754922] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1846.762197] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1846.786683] Lustre: Skipped 1 previous similar message [ 1846.847966] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1846.919698] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:202 to 0x2c0000401:225) [ 1846.928652] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:202 to 0x280000401:225) [ 1848.852768] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1875.836244] Lustre: DEBUG MARKER: == sanity-scrub test 1c: Auto detect kinds of OI file(s) removed/recreated cases ========================================================== 04:04:23 (1743494663) [ 1915.107905] Lustre: Failing over lustre-MDT0000 [ 1915.584670] Lustre: server umount lustre-MDT0000 complete [ 1918.444814] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1918.446808] 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 [ 1918.454387] LustreError: 32898:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1918.484941] Lustre: Skipped 6 previous similar messages [ 1918.526468] LustreError: 32898:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 23 previous similar messages [ 1923.173699] Lustre: Failing over lustre-MDT0001 [ 1923.177255] LustreError: 19112:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743494715 with bad export cookie 15735431097706076813 [ 1923.188589] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1923.201098] LustreError: 19112:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1923.880485] Lustre: server umount lustre-MDT0001 complete [ 1933.366095] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1941.924235] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 1958.140369] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1958.285094] Lustre: lustre-MDT0000: invalid oi count 63, remove them, then set it to 64 [ 1968.607946] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7df9909180 x1828185744992000/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1969.244221] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1969.248365] Lustre: Skipped 1 previous similar message [ 1969.326325] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1973.357822] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 1973.379674] Lustre: Skipped 2 previous similar messages [ 1975.813693] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1990.545771] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1990.603389] Lustre: lustre-MDT0001: invalid oi count 63, remove them, then set it to 64 [ 1990.806300] Lustre: 36391:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 1991.027553] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 1991.340376] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:233 to 0x280000400:257) [ 1991.376514] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:234 to 0x2c0000400:257) [ 1996.268700] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1996.369933] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1996.442542] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 1996.458726] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:266 to 0x2c0000401:289) [ 1998.703501] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2048.506162] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 2084.617041] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 2125.252907] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2132.419227] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 2175.762591] Lustre: Failing over lustre-MDT0000 [ 2176.350194] Lustre: server umount lustre-MDT0000 complete [ 2180.582490] 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 [ 2180.587387] LustreError: 36196:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2180.616886] Lustre: Skipped 3 previous similar messages [ 2180.617251] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2180.634629] LustreError: 36196:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 11 previous similar messages [ 2183.235650] LustreError: 19112:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743494975 with bad export cookie 15735431097706104386 [ 2183.239794] Lustre: Failing over lustre-MDT0001 [ 2183.242201] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2183.264087] LustreError: 19112:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2184.093306] Lustre: server umount lustre-MDT0001 complete [ 2192.362651] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2201.055222] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743494977/real 1743494977] req@ffff8f7cd5740bc0 x1828185745176192/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743494993 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 2201.091201] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 8 previous similar messages [ 2206.516245] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2227.587707] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2227.659890] Lustre: lustre-MDT0000: invalid oi count 58, remove them, then set it to 64 [ 2228.767597] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7cda4950c0 x1828185745179264/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 2229.315845] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2229.319958] Lustre: Skipped 1 previous similar message [ 2229.382297] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2235.937484] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2245.616509] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 2245.620278] Lustre: Skipped 4 previous similar messages [ 2249.839259] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2249.952443] Lustre: lustre-MDT0001: invalid oi count 58, remove them, then set it to 64 [ 2250.296159] Lustre: 42204:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 2250.805882] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:297 to 0x280000400:321) [ 2250.838025] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:298 to 0x2c0000400:321) [ 2255.850961] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2255.932984] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2255.980947] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:330 to 0x280000401:353) [ 2255.981782] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:329 to 0x2c0000401:353) [ 2256.584945] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2301.914551] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 2336.607808] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 2377.146584] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2425.449374] Lustre: Failing over lustre-MDT0000 [ 2426.190379] Lustre: server umount lustre-MDT0000 complete [ 2429.921559] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2429.929551] Lustre: Skipped 5 previous similar messages [ 2432.921654] LustreError: 19114:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743495224 with bad export cookie 15735431097706131609 [ 2432.924337] Lustre: Failing over lustre-MDT0001 [ 2432.935671] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2432.941821] LustreError: 19114:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2433.408907] Lustre: server umount lustre-MDT0001 complete [ 2441.230354] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2451.424188] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743495227/real 1743495227] req@ffff8f7cd8c5d0c0 x1828185745359744/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743495243 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 2451.443654] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 2451.804870] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2470.139504] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2470.178908] Lustre: lustre-MDT0000: invalid oi count 56, remove them, then set it to 64 [ 2477.927816] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2484.303434] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2495.480473] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 2495.484118] Lustre: Skipped 4 previous similar messages [ 2499.005828] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2499.085798] Lustre: lustre-MDT0001: invalid oi count 56, remove them, then set it to 64 [ 2499.493430] Lustre: 47824:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 2499.821060] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 2499.824449] LustreError: Skipped 2 previous similar messages [ 2500.082762] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2500.211732] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:361 to 0x2c0000400:385) [ 2500.241361] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:362 to 0x280000400:385) [ 2505.289378] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 2505.388430] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 2505.388877] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 2506.538809] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2535.539770] Lustre: DEBUG MARKER: == sanity-scrub test 2: Trigger OI scrub when MDT mounts for backup/restore case ========================================================== 04:15:24 (1743495324) [ 2563.992814] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 2595.305053] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 2595.314177] Lustre: Skipped 1 previous similar message [ 2633.364222] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2684.286643] Lustre: Failing over lustre-MDT0000 [ 2684.392874] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2684.398236] Lustre: Skipped 3 previous similar messages [ 2684.759805] Lustre: server umount lustre-MDT0000 complete [ 2690.904168] LustreError: 34319:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743495482 with bad export cookie 15735431097706158832 [ 2690.915938] Lustre: Failing over lustre-MDT0001 [ 2690.925630] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2691.413419] Lustre: server umount lustre-MDT0001 complete [ 2700.565466] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2711.008905] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743495486/real 1743495486] req@ffff8f7cd5717340 x1828185745545088/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743495502 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 2711.043587] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 2711.052723] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 2711.070060] Lustre: Skipped 8 previous similar messages [ 2716.982464] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2718.930483] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2732.653833] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2748.742232] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2750.573799] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2768.972430] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2769.000270] Lustre: lustre-MDT0000: reset Object Index mappings [ 2786.468324] LustreError: 25576:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2786.492859] LustreError: 25576:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 25 previous similar messages [ 2786.718792] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2786.740020] Lustre: Skipped 3 previous similar messages [ 2786.848984] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2789.819969] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 2789.823273] Lustre: Skipped 4 previous similar messages [ 2793.411643] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2808.308167] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2808.321700] Lustre: lustre-MDT0001: reset Object Index mappings [ 2808.503073] Lustre: 54663:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 2809.066588] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:425 to 0x2c0000400:449) [ 2809.069735] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:426 to 0x280000400:449) [ 2814.449523] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2814.512587] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2814.546905] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:458 to 0x280000401:481) [ 2814.550081] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:457 to 0x2c0000401:481) [ 2815.287395] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2840.175986] Lustre: DEBUG MARKER: == sanity-scrub test 4a: Auto trigger OI scrub if bad OI mapping was found (1) ========================================================== 04:20:28 (1743495628) [ 2875.211840] Lustre: Failing over lustre-MDT0000 [ 2875.686596] Lustre: server umount lustre-MDT0000 complete [ 2882.308395] Lustre: Failing over lustre-MDT0001 [ 2882.317957] LustreError: 21027:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743495674 with bad export cookie 15735431097706186055 [ 2882.321853] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2882.333358] LustreError: 21027:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 7 previous similar messages [ 2882.894099] Lustre: server umount lustre-MDT0001 complete [ 2892.704655] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2910.568957] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2912.336084] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 2926.586955] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2943.514782] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 2945.360078] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 2965.620979] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2965.634283] Lustre: lustre-MDT0000: reset Object Index mappings [ 2977.380461] Lustre: Evicted from MGS (at 192.168.206.105@tcp) after server handle changed from 0x0 to 0xda5f7b36a669f0f5 [ 2978.106080] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2984.116614] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2999.882619] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2999.945096] Lustre: lustre-MDT0001: reset Object Index mappings [ 3000.832031] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:489 to 0x280000400:513) [ 3000.836053] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:490 to 0x2c0000400:513) [ 3005.938230] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3005.995445] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3006.097175] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:522 to 0x280000401:545) [ 3006.098624] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:521 to 0x2c0000401:545) [ 3007.517735] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3021.526609] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32015: rc = 0 [ 3022.811906] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240003ab1:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 3058.332809] Lustre: DEBUG MARKER: == sanity-scrub test 4b: Auto trigger OI scrub if bad OI mapping was found (2) ========================================================== 04:24:06 (1743495846) [ 3098.785812] Lustre: Failing over lustre-MDT0000 [ 3099.270591] Lustre: server umount lustre-MDT0000 complete [ 3103.199785] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3103.216406] LustreError: Skipped 3 previous similar messages [ 3105.744765] Lustre: Failing over lustre-MDT0001 [ 3105.749595] LustreError: 19113:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743495897 with bad export cookie 15735431097706213621 [ 3105.753752] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3105.790289] LustreError: 19113:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3106.316560] Lustre: server umount lustre-MDT0001 complete [ 3115.730367] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3124.704106] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743495900/real 1743495900] req@ffff8f7cd21d5c40 x1828185745826816/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743495916 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 3124.715139] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 22 previous similar messages [ 3133.259360] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3134.904140] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3151.006266] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3169.262365] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3171.200859] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3193.644954] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3193.673117] Lustre: lustre-MDT0000: reset Object Index mappings [ 3200.543603] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7cd21d50c0 x1828185745831424/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 3201.386285] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3208.294950] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3222.731887] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3222.746204] Lustre: lustre-MDT0001: reset Object Index mappings [ 3223.066443] Lustre: 63052:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 3223.077558] Lustre: 63052:0:(mgc_request_server.c:553:mgc_llog_local_copy()) Skipped 1 previous similar message [ 3223.665559] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:554 to 0x2c0000400:577) [ 3223.674206] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:553 to 0x280000400:577) [ 3228.651082] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3228.730373] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3228.785592] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:585 to 0x280000401:609) [ 3228.785641] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:586 to 0x2c0000401:609) [ 3229.771370] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3245.853251] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004a52:0x1:0x0]/32023: rc = 0 [ 3247.181861] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/32026 with flags 0x52: rc = 0 [ 3388.924063] Lustre: DEBUG MARKER: == sanity-scrub test 4c: Auto trigger OI scrub if bad OI mapping was found (3) ========================================================== 04:29:37 (1743496177) [ 3455.390720] Lustre: Failing over lustre-MDT0000 [ 3456.189754] Lustre: server umount lustre-MDT0000 complete [ 3459.044179] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3459.054968] LustreError: 62341:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 3459.061977] Lustre: Skipped 15 previous similar messages [ 3459.108788] LustreError: 62341:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 38 previous similar messages [ 3462.445020] Lustre: Failing over lustre-MDT0001 [ 3462.448413] LustreError: 19112:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743496254 with bad export cookie 15735431097706241187 [ 3462.450058] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3462.492264] LustreError: 19112:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3463.320603] Lustre: server umount lustre-MDT0001 complete [ 3472.084693] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3493.121189] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3495.178671] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 3511.438393] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3528.486872] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3529.928837] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 3550.050423] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3550.080761] Lustre: lustre-MDT0000: reset Object Index mappings [ 3557.886159] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3557.888621] Lustre: Skipped 5 previous similar messages [ 3557.934170] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3565.009721] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3574.246985] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 3574.257161] Lustre: Skipped 15 previous similar messages [ 3579.197106] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3580.144692] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3580.245802] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:617 to 0x280000400:641) [ 3580.248421] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:618 to 0x2c0000400:641) [ 3585.574200] Lustre: lustre-MDT0000: Recovery over after 0:05, of 1 clients 1 recovered and 0 were evicted. [ 3585.647386] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:649 to 0x280000401:673) [ 3585.647990] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:650 to 0x2c0000401:673) [ 3586.880713] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3604.994516] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200005222:0x1:0x0]/64027: rc = 0 [ 3608.493701] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004a51:0x1:0x0]/64022 with flags 0x52: rc = 0 [ 3726.025973] Lustre: DEBUG MARKER: == sanity-scrub test 4d: FID in LMA mismatch with object FID won't block create ========================================================== 04:35:14 (1743496514) [ 3752.431926] Lustre: *** cfs_fail_loc=19b, val=0*** [ 3752.433763] Lustre: Skipped 1 previous similar message [ 3752.953262] Lustre: *** cfs_fail_loc=19b, val=0*** [ 3752.957058] Lustre: Skipped 23 previous similar messages [ 3754.000738] Lustre: *** cfs_fail_loc=19b, val=0*** [ 3754.002709] Lustre: Skipped 181 previous similar messages [ 3756.018594] Lustre: *** cfs_fail_loc=19b, val=0*** [ 3756.025080] Lustre: Skipped 101 previous similar messages [ 3790.174232] Lustre: DEBUG MARKER: == sanity-scrub test 4e: FID reuse can be fixed ========== 04:36:18 (1743496578) [ 3799.060633] Lustre: *** cfs_fail_loc=1a0, val=0*** [ 3799.063395] Lustre: Skipped 147 previous similar messages [ 3827.046288] Lustre: DEBUG MARKER: == sanity-scrub test 5: OI scrub state machine =========== 04:36:54 (1743496614) [ 3846.626343] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3846.631717] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3846.644149] LustreError: Skipped 3 previous similar messages [ 3846.663440] Lustre: Skipped 2 previous similar messages [ 3851.746441] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3851.762763] Lustre: Skipped 4 previous similar messages [ 3852.976581] Lustre: server umount lustre-MDT0000 complete [ 3859.370556] LustreError: 19114:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743496651 with bad export cookie 15735431097706285196 [ 3859.398362] LustreError: 19114:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3861.990669] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3861.994106] Lustre: Skipped 1 previous similar message [ 3864.992273] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3864.995097] Lustre: Skipped 1 previous similar message [ 3866.089436] Lustre: server umount lustre-MDT0001 complete [ 3879.942673] Lustre: server umount lustre-OST0000 complete [ 3886.271490] Lustre: server umount lustre-OST0001 complete [ 3897.748667] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_hostid [ 3915.938250] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 3939.890136] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3955.223900] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3967.014978] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 3980.510951] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4013.508979] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 4035.343164] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4035.531638] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4036.134382] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall in log lustre-MDT0000 [ 4036.139266] Lustre: Skipped 1 previous similar message [ 4036.251534] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4036.405607] Lustre: lustre-MDT0000: new disk, initializing [ 4036.801155] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4042.993415] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4060.207609] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4060.429573] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4060.734203] Lustre: 76069:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 4060.768555] Lustre: 76069:0:(mgc_request_server.c:553:mgc_llog_local_copy()) Skipped 1 previous similar message [ 4060.823379] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4060.836286] Lustre: Skipped 1 previous similar message [ 4061.014400] Lustre: lustre-MDT0001: new disk, initializing [ 4061.210350] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4061.235093] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4068.552170] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4076.628735] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 4076.637635] Lustre: Skipped 1 previous similar message [ 4087.468207] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4087.680696] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4088.219201] Lustre: lustre-OST0000: new disk, initializing [ 4088.249157] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4089.658343] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4089.662491] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4089.927401] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4098.009990] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4115.687336] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4115.817119] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4116.106822] Lustre: lustre-OST0001: new disk, initializing [ 4116.112664] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4117.433912] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4117.456471] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4117.642640] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4126.572253] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4144.331813] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4152.807074] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 4192.762632] Lustre: Failing over lustre-MDT0000 [ 4193.137292] Lustre: server umount lustre-MDT0000 complete [ 4194.271836] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4194.284177] Lustre: Skipped 9 previous similar messages [ 4194.308303] LustreError: 76138:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4194.327244] LustreError: 76138:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 19 previous similar messages [ 4199.266959] Lustre: Failing over lustre-MDT0001 [ 4199.284776] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4199.289368] LustreError: Skipped 1 previous similar message [ 4199.395583] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4199.405887] Lustre: Skipped 1 previous similar message [ 4200.167795] Lustre: server umount lustre-MDT0001 complete [ 4210.354587] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4228.099215] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4229.756587] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4242.632412] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4259.845359] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4261.507308] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4281.912631] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4281.929459] Lustre: lustre-MDT0000: reset Object Index mappings [ 4281.931615] Lustre: Skipped 1 previous similar message [ 4295.339358] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4295.342222] Lustre: Skipped 5 previous similar messages [ 4295.407980] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4299.433185] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 4299.441465] Lustre: Skipped 4 previous similar messages [ 4301.536230] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4316.579754] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4316.624287] Lustre: lustre-MDT0001: reset Object Index mappings [ 4317.639387] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 4317.645189] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 4322.807582] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4322.843396] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4322.919818] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 4322.919818] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 4324.132402] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4343.374822] Lustre: *** cfs_fail_loc=190, val=3*** [ 4343.376691] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x1:0x0]/64002: rc = 0 [ 4344.477226] Lustre: *** cfs_fail_loc=190, val=3*** [ 4344.479135] Lustre: Skipped 1 previous similar message [ 4345.557529] Lustre: *** cfs_fail_loc=190, val=3*** [ 4346.758813] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32007 with flags 0x52: rc = 0 [ 4348.575671] Lustre: *** cfs_fail_loc=190, val=3*** [ 4348.577623] Lustre: Skipped 2 previous similar messages [ 4352.863077] Lustre: *** cfs_fail_loc=190, val=3*** [ 4352.873783] Lustre: Skipped 2 previous similar messages [ 4362.930676] Lustre: Failing over lustre-MDT0000 [ 4363.302472] Lustre: server umount lustre-MDT0000 complete [ 4369.131045] Lustre: Failing over lustre-MDT0001 [ 4369.658585] Lustre: server umount lustre-MDT0001 complete [ 4386.733424] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4389.087165] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497165/real 1743497165] req@ffff8f7dfcf36200 x1828185746467072/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743497181 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4389.127533] Lustre: 16278:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 23 previous similar messages [ 4394.464410] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7dd8c94540 x1828185746469248/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4402.373849] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4416.552285] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4417.234788] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:97) [ 4417.244845] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:97) [ 4418.248854] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:97) [ 4418.249842] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:97) [ 4423.511823] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4432.742756] Lustre: Failing over lustre-MDT0000 [ 4433.085861] Lustre: server umount lustre-MDT0000 complete [ 4439.014942] Lustre: Failing over lustre-MDT0001 [ 4439.021664] LustreError: 76898:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743497230 with bad export cookie 15735431097706400003 [ 4439.048639] LustreError: 76898:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 14 previous similar messages [ 4439.600250] Lustre: server umount lustre-MDT0001 complete [ 4456.330178] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4456.613668] Lustre: *** cfs_fail_loc=190, val=3*** [ 4456.615045] Lustre: Skipped 3 previous similar messages [ 4458.975285] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497234/real 1743497234] req@ffff8f7dfb337340 x1828185746502144/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743497250 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4459.016197] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 4469.775747] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4474.847874] Lustre: *** cfs_fail_loc=190, val=3*** [ 4474.849797] Lustre: Skipped 5 previous similar messages [ 4483.799121] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4484.487658] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 4484.497600] LustreError: Skipped 5 previous similar messages [ 4484.870080] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:129) [ 4484.909225] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:129) [ 4490.320935] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:129) [ 4490.339498] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:129) [ 4491.012059] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4511.643526] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240000402:0x1:0x0]/32007 with flags 0x52: rc = 0 [ 4511.754560] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200000402:0x45:0x0]/175: rc = 0 [ 4533.891903] Lustre: DEBUG MARKER: == sanity-scrub test 6: OI scrub resumes from last checkpoint ========================================================== 04:48:42 (1743497322) [ 4573.494083] Lustre: Failing over lustre-MDT0000 [ 4573.900158] Lustre: server umount lustre-MDT0000 complete [ 4579.716367] Lustre: Failing over lustre-MDT0001 [ 4580.156265] Lustre: server umount lustre-MDT0001 complete [ 4588.621739] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4598.816237] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497374/real 1743497374] req@ffff8f7ccf825680 x1828185746641152/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743497390 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4598.857969] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 4604.178419] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4605.617176] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 4618.668195] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4634.604340] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 4636.579858] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 4655.056451] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4655.076570] Lustre: lustre-MDT0000: reset Object Index mappings [ 4674.656136] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7cc5b44b00 x1828185746645504/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 4681.675120] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4695.360184] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4695.376364] Lustre: lustre-MDT0001: reset Object Index mappings [ 4695.501852] Lustre: 90612:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 4695.506368] Lustre: 90612:0:(mgc_request_server.c:553:mgc_llog_local_copy()) Skipped 5 previous similar messages [ 4695.880430] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:193) [ 4695.918993] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:193) [ 4701.254791] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 4701.258563] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 4701.801190] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4716.004444] Lustre: *** cfs_fail_loc=190, val=2*** [ 4716.005963] Lustre: Skipped 16 previous similar messages [ 4716.010290] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x1:0x0]/32041: rc = 0 [ 4718.311107] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240001b71:0x1:0x0]/32004 with flags 0x52: rc = 0 [ 4734.441554] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200001b72:0x45:0x0]/172: rc = 0 [ 4752.299687] Lustre: Failing over lustre-MDT0000 [ 4752.358493] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4752.664376] Lustre: server umount lustre-MDT0000 complete [ 4758.254565] Lustre: Failing over lustre-MDT0001 [ 4758.688949] Lustre: server umount lustre-MDT0001 complete [ 4773.852308] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4780.063243] Lustre: *** cfs_fail_loc=190, val=3*** [ 4780.065160] Lustre: Skipped 26 previous similar messages [ 4790.285908] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4795.879954] LustreError: 92516:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0001: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4795.888023] LustreError: 92516:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 79 previous similar messages [ 4804.687076] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4805.294054] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:169 to 0x2c0000400:225) [ 4805.295140] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:170 to 0x280000400:225) [ 4810.801594] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:225) [ 4810.805459] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:225) [ 4811.000650] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4840.230808] Lustre: DEBUG MARKER: == sanity-scrub test 7: System is available during OI scrub scanning ========================================================== 04:53:49 (1743497629) [ 4866.871898] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 4894.891882] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 4928.694106] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4935.350552] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 4992.331958] Lustre: Failing over lustre-MDT0000 [ 4992.684211] Lustre: server umount lustre-MDT0000 complete [ 4992.995787] Lustre: lustre-MDT0000-lwp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4993.010291] Lustre: Skipped 30 previous similar messages [ 4997.565595] Lustre: Failing over lustre-MDT0001 [ 4997.569166] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4997.577890] LustreError: Skipped 4 previous similar messages [ 4998.146355] Lustre: server umount lustre-MDT0001 complete [ 5005.288697] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5014.431115] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743497790/real 1743497790] req@ffff8f7cd98f8600 x1828185746885376/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743497806 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 5014.453687] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 26 previous similar messages [ 5019.068212] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5020.483500] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5031.937524] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5045.110984] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5046.596258] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5061.955985] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5061.993151] Lustre: lustre-MDT0000: reset Object Index mappings [ 5068.440519] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5068.445802] Lustre: Skipped 9 previous similar messages [ 5068.496353] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5068.499469] Lustre: Skipped 4 previous similar messages [ 5073.617235] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5083.113786] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 5083.119819] Lustre: Skipped 24 previous similar messages [ 5085.169288] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5085.488462] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 5085.494777] LustreError: Skipped 3 previous similar messages [ 5085.763713] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:266 to 0x2c0000400:289) [ 5085.770732] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:265 to 0x280000400:289) [ 5090.795486] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5090.809884] Lustre: Skipped 4 previous similar messages [ 5090.839248] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5090.849074] Lustre: Skipped 4 previous similar messages [ 5090.889088] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:265 to 0x2c0000401:289) [ 5090.891703] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:266 to 0x280000401:289) [ 5091.737692] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5105.757677] Lustre: *** cfs_fail_loc=190, val=3*** [ 5105.759710] Lustre: Skipped 19 previous similar messages [ 5105.761395] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200002b12:0x1:0x0]/32004: rc = 0 [ 5105.780884] Lustre: Skipped 1 previous similar message [ 5107.030596] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240002b11:0x1:0x0]/32032 with flags 0x52: rc = 0 [ 5137.759795] Lustre: DEBUG MARKER: == sanity-scrub test 8: Control OI scrub manually ======== 04:58:46 (1743497926) [ 5199.958132] Lustre: Failing over lustre-MDT0000 [ 5200.259378] Lustre: server umount lustre-MDT0000 complete [ 5205.558589] Lustre: Failing over lustre-MDT0001 [ 5205.562115] LustreError: 77750:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743497997 with bad export cookie 15735431097706497989 [ 5205.572902] LustreError: 77750:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 11 previous similar messages [ 5206.037172] Lustre: server umount lustre-MDT0001 complete [ 5212.737510] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5224.887639] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5226.229660] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5236.891613] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5250.585298] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5251.888031] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5266.724526] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5266.739841] Lustre: lustre-MDT0000: reset Object Index mappings [ 5266.742364] Lustre: Skipped 1 previous similar message [ 5280.333381] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5290.796499] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5291.257750] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:329 to 0x2c0000400:353) [ 5291.266584] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:330 to 0x280000400:353) [ 5293.344335] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:329 to 0x280000401:353) [ 5293.345070] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:330 to 0x2c0000401:353) [ 5295.342187] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5342.636770] Lustre: DEBUG MARKER: == sanity-scrub test 9: OI scrub speed control =========== 05:02:11 (1743498131) [ 5366.632384] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 5390.888105] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 5419.554746] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5581.273710] Lustre: Failing over lustre-MDT0000 [ 5582.366724] Lustre: server umount lustre-MDT0000 complete [ 5584.362056] LustreError: 104575:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 5584.368842] LustreError: 104575:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 26 previous similar messages [ 5586.877488] Lustre: Failing over lustre-MDT0001 [ 5587.995865] Lustre: server umount lustre-MDT0001 complete [ 5594.507098] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5605.855314] Lustre: 16276:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743498381/real 1743498381] req@ffff8f7cd55cd680 x1828185747275776/t0(0) o400->lustre-MDT0001-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743498397 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 5605.860142] Lustre: lustre-MDT0001-lwp-OST0001: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5605.905869] Lustre: 16276:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 24 previous similar messages [ 5605.917044] Lustre: Skipped 13 previous similar messages [ 5609.869224] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5611.068490] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 5625.164165] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5640.309593] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 5641.609895] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 5659.853941] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 5659.901362] Lustre: lustre-MDT0000: reset Object Index mappings [ 5659.904380] Lustre: Skipped 1 previous similar message [ 5682.170288] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5682.175563] Lustre: Skipped 3 previous similar messages [ 5682.237851] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5682.241722] Lustre: Skipped 1 previous similar message [ 5686.344310] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5696.417556] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5696.603205] Lustre: 113065:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 5696.608392] Lustre: 113065:0:(mgc_request_server.c:553:mgc_llog_local_copy()) Skipped 3 previous similar messages [ 5696.732567] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_connect to node 0@lo failed: rc = -114 [ 5696.735735] LustreError: Skipped 2 previous similar messages [ 5696.923519] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:394 to 0x2c0000400:417) [ 5696.932333] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:393 to 0x280000400:417) [ 5699.942228] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5699.948542] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 5699.967267] Lustre: Skipped 9 previous similar messages [ 5699.995692] Lustre: Skipped 1 previous similar message [ 5700.016319] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5700.019667] Lustre: Skipped 1 previous similar message [ 5700.036545] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:394 to 0x280000401:417) [ 5700.038344] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:393 to 0x2c0000401:417) [ 5701.509870] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5774.768788] Lustre: DEBUG MARKER: == sanity-scrub test 10a: non-stopped OI scrub should auto restarts after MDS remount (1) ========================================================== 05:09:23 (1743498563) [ 5797.831312] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 5823.427471] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 5823.430235] Lustre: Skipped 1 previous similar message [ 5852.312173] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6091.565956] Lustre: Failing over lustre-MDT0000 [ 6091.840239] Lustre: server umount lustre-MDT0000 complete [ 6095.913551] LustreError: 76898:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743498887 with bad export cookie 15735431097706794404 [ 6095.914645] Lustre: Failing over lustre-MDT0001 [ 6095.918218] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6095.918228] LustreError: Skipped 2 previous similar messages [ 6095.924446] LustreError: 76898:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 5 previous similar messages [ 6096.267440] Lustre: server umount lustre-MDT0001 complete [ 6102.763647] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6113.311387] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6114.412368] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 6123.483089] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 6133.720733] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6134.863548] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 6147.456432] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 6147.485798] Lustre: lustre-MDT0000: reset Object Index mappings [ 6147.488412] Lustre: Skipped 1 previous similar message [ 6165.983649] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7dfa2e0040 x1828185747571456/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 6170.572451] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6179.669436] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6180.229362] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:481) [ 6180.233676] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:481) [ 6184.895749] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6185.315456] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:481) [ 6185.317540] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:481) [ 6195.906432] Lustre: *** cfs_fail_loc=190, val=1*** [ 6195.909113] Lustre: Skipped 46 previous similar messages [ 6195.910519] Lustre: lustre-MDT0000: trigger partial OI scrub for RPC inconsistency, checking FID [0x200004282:0x1:0x0]/32004: rc = 0 [ 6198.155724] Lustre: lustre-MDT0001: trigger OI scrub by RPC for [0x240004281:0x1:0x0]/64032 with flags 0x52: rc = 0 [ 6205.243809] Lustre: Failing over lustre-MDT0000 [ 6205.429095] Lustre: server umount lustre-MDT0000 complete [ 6205.922622] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 6205.929169] Lustre: Skipped 7 previous similar messages [ 6205.934635] LustreError: 76893:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6205.943618] LustreError: 76893:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 11 previous similar messages [ 6209.424791] Lustre: Failing over lustre-MDT0001 [ 6209.747908] Lustre: server umount lustre-MDT0001 complete [ 6219.074355] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 6223.777851] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6228.767181] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743499004/real 1743499004] req@ffff8f7ce2e99740 x1828185747605120/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743499020 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 6228.780475] Lustre: 16275:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 19 previous similar messages [ 6233.264388] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6233.753019] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:513) [ 6233.769750] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:513) [ 6238.099083] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6238.813614] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:513) [ 6238.813938] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:513) [ 6244.823327] Lustre: Failing over lustre-MDT0000 [ 6245.080273] Lustre: server umount lustre-MDT0000 complete [ 6249.325733] Lustre: Failing over lustre-MDT0001 [ 6249.608744] Lustre: server umount lustre-MDT0001 complete [ 6259.200659] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 6259.339146] Lustre: *** cfs_fail_loc=190, val=1*** [ 6259.341129] Lustre: Skipped 25 previous similar messages [ 6279.031539] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6288.902161] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6289.384215] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6289.388371] Lustre: Skipped 6 previous similar messages [ 6289.449304] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:458 to 0x2c0000400:545) [ 6289.455191] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:457 to 0x280000400:545) [ 6290.506454] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:457 to 0x280000401:545) [ 6290.511650] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:458 to 0x2c0000401:545) [ 6294.061441] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6315.238756] Lustre: DEBUG MARKER: == sanity-scrub test 11: OI scrub skips the new created objects only once ========================================================== 05:18:24 (1743499104) [ 6335.025730] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 6357.751985] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 6357.755222] Lustre: Skipped 1 previous similar message [ 6383.466715] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6425.842646] Lustre: DEBUG MARKER: == sanity-scrub test 12: OI scrub can rebuild invalid /O entries ========================================================== 05:20:15 (1743499215) [ 6431.870125] Lustre: *** cfs_fail_loc=195, val=0*** [ 6432.399431] Lustre: *** cfs_fail_loc=195, val=0*** [ 6432.401263] Lustre: Skipped 31 previous similar messages [ 6436.199300] Lustre: Failing over lustre-OST0000 [ 6436.308167] Lustre: server umount lustre-OST0000 complete [ 6445.908996] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6446.009680] Lustre: 129972:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 6446.015181] Lustre: 129972:0:(mgc_request_server.c:553:mgc_llog_local_copy()) Skipped 3 previous similar messages [ 6446.186821] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 6446.189558] Lustre: Skipped 3 previous similar messages [ 6448.185038] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 6448.187393] Lustre: Skipped 3 previous similar messages [ 6448.223638] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 6448.224385] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 6448.239064] Lustre: Skipped 3 previous similar messages [ 6448.244212] Lustre: Skipped 19 previous similar messages [ 6451.809281] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6647.455514] Lustre: DEBUG MARKER: == sanity-scrub test 13: OI scrub can rebuild missed /O entries ========================================================== 05:23:57 (1743499437) [ 6651.508560] Lustre: *** cfs_fail_loc=196, val=0*** [ 6651.512843] Lustre: Skipped 31 previous similar messages [ 6656.584748] Lustre: Failing over lustre-OST0000 [ 6656.694460] Lustre: server umount lustre-OST0000 complete [ 6658.529718] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 6658.535039] LustreError: Skipped 6 previous similar messages [ 6665.042735] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6665.248547] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 6670.455396] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6863.021268] Lustre: DEBUG MARKER: == sanity-scrub test 14: OI scrub can repair OST objects under lost+found ========================================================== 05:27:32 (1743499652) [ 6869.710353] Lustre: *** cfs_fail_loc=196, val=0*** [ 6869.715252] Lustre: Skipped 63 previous similar messages [ 6873.939608] Lustre: *** cfs_fail_loc=196, val=0*** [ 6873.944800] Lustre: Skipped 287 previous similar messages [ 6882.192280] Lustre: *** cfs_fail_loc=196, val=0*** [ 6882.194446] Lustre: Skipped 543 previous similar messages [ 6890.951744] Lustre: Failing over lustre-OST0000 [ 6891.098228] Lustre: server umount lustre-OST0000 complete [ 6892.007343] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 6892.009042] LustreError: 87325:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 6892.026394] Lustre: Skipped 16 previous similar messages [ 6892.033556] LustreError: 87325:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 34 previous similar messages [ 6901.013309] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6901.367345] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 6906.032911] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6917.093728] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6917.098675] Lustre: Skipped 3 previous similar messages [ 6917.600134] Lustre: server umount lustre-MDT0000 complete [ 6921.201187] LustreError: 77750:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743499713 with bad export cookie 15735431097707497008 [ 6921.204846] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6921.206815] LustreError: 77750:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 9 previous similar messages [ 6921.211594] LustreError: Skipped 2 previous similar messages [ 6921.493967] Lustre: server umount lustre-MDT0001 complete [ 6936.108964] Lustre: server umount lustre-OST0000 complete [ 6938.400571] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743499714/real 1743499714] req@ffff8f7dc8102e40 x1828185748074112/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743499730 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 6938.415423] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 16 previous similar messages [ 6940.279330] Lustre: server umount lustre-OST0001 complete [ 6953.023590] Lustre: DEBUG MARKER: == sanity-scrub test 15: Dryrun mode OI scrub ============ 05:29:02 (1743499742) [ 6968.189601] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_hostid [ 6978.990675] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 6991.422210] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 6998.632049] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7005.875289] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7012.691455] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7029.356059] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 7041.045241] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7041.158689] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7041.459623] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall in log lustre-MDT0000 [ 7041.462850] Lustre: Skipped 1 previous similar message [ 7041.506538] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 7041.567083] Lustre: lustre-MDT0000: new disk, initializing [ 7041.654376] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 7041.658235] Lustre: Skipped 1 previous similar message [ 7041.680326] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 7045.575404] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7056.009080] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7056.096419] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7056.208286] Lustre: 139047:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 7056.215714] Lustre: 139047:0:(mgc_request_server.c:553:mgc_llog_local_copy()) Skipped 2 previous similar messages [ 7056.250955] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 7056.254205] Lustre: Skipped 1 previous similar message [ 7056.302426] Lustre: lustre-MDT0001: new disk, initializing [ 7056.415160] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 7056.424505] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 7060.469599] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7071.786647] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7071.855788] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7072.094564] Lustre: lustre-OST0000: new disk, initializing [ 7072.103327] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 7073.657345] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 7073.662954] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 7073.770910] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 7077.593247] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7087.460587] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7087.559333] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7087.706392] Lustre: lustre-OST0001: new disk, initializing [ 7087.710930] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 7089.073226] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 7089.078080] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 7089.160981] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 7093.749210] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7104.808844] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7135.267143] Lustre: Failing over lustre-MDT0000 [ 7135.508276] Lustre: server umount lustre-MDT0000 complete [ 7138.886572] Lustre: Failing over lustre-MDT0001 [ 7139.201900] Lustre: server umount lustre-MDT0001 complete [ 7144.986544] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 7155.101814] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7156.214781] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 7165.461816] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 7176.263766] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 7177.381936] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null) [ 7188.045272] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 7188.064308] Lustre: lustre-MDT0000: reset Object Index mappings [ 7188.066616] Lustre: Skipped 1 previous similar message [ 7208.930042] Lustre: Evicted from MGS (at 192.168.206.105@tcp) after server handle changed from 0x0 to 0xda5f7b36a67fb0b8 [ 7208.939216] Lustre: MGC192.168.206.105@tcp: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 7208.949167] Lustre: Skipped 5 previous similar messages [ 7209.295971] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 7209.316239] Lustre: Skipped 2 previous similar messages [ 7212.668518] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7221.034170] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7221.531382] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:41 to 0x280000400:65) [ 7221.539253] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:42 to 0x2c0000400:65) [ 7225.317422] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7226.604283] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 7226.612838] Lustre: Skipped 2 previous similar messages [ 7226.647287] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 7226.651443] Lustre: Skipped 2 previous similar messages [ 7226.677867] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 7226.677867] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:42 to 0x280000401:65) [ 7275.951653] Lustre: DEBUG MARKER: == sanity-scrub test 16: Initial OI scrub can rebuild crashed index objects ========================================================== 05:34:25 (1743500065) [ 7293.648842] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 7336.910676] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7372.034102] Lustre: Failing over lustre-MDT0000 [ 7372.049502] Lustre: *** cfs_fail_loc=199, val=0*** [ 7372.051642] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000001:0x3:0x0]: rc = 0 [ 7372.057930] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2:0x0]: rc = 0 [ 7372.064163] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x9:0x0]: rc = 0 [ 7372.070381] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xa:0x0]: rc = 0 [ 7372.076502] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xb:0x0]: rc = 0 [ 7372.091204] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xc:0x0]: rc = 0 [ 7372.098515] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xd:0x0]: rc = 0 [ 7372.104969] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0xe:0x0]: rc = 0 [ 7372.112609] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x13:0x0]: rc = 0 [ 7372.120682] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x14:0x0]: rc = 0 [ 7372.129966] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x15:0x0]: rc = 0 [ 7372.138538] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x16:0x0]: rc = 0 [ 7372.146359] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x17:0x0]: rc = 0 [ 7372.154768] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x18:0x0]: rc = 0 [ 7372.160973] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x19:0x0]: rc = 0 [ 7372.167740] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 7372.175574] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 7372.183236] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 7372.189455] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 7372.198077] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1e:0x0]: rc = 0 [ 7372.205895] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 7372.212474] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x20:0x0]: rc = 0 [ 7372.219515] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x21:0x0]: rc = 0 [ 7372.225347] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x22:0x0]: rc = 0 [ 7372.231558] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x23:0x0]: rc = 0 [ 7372.238175] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x25:0x0]: rc = 0 [ 7372.244086] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x26:0x0]: rc = 0 [ 7372.250531] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x27:0x0]: rc = 0 [ 7372.257231] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x28:0x0]: rc = 0 [ 7372.264453] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x29:0x0]: rc = 0 [ 7372.270289] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 7372.278053] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 7372.283781] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 7372.290648] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 7372.298391] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 7372.309691] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 7372.316689] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x30:0x0]: rc = 0 [ 7372.323883] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x31:0x0]: rc = 0 [ 7372.331179] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x32:0x0]: rc = 0 [ 7372.338426] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x33:0x0]: rc = 0 [ 7372.345437] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x34:0x0]: rc = 0 [ 7372.354498] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000003:0x35:0x0]: rc = 0 [ 7372.362182] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x1:0x0]: rc = 0 [ 7372.369647] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x2:0x0]: rc = 0 [ 7372.378184] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x3:0x0]: rc = 0 [ 7372.385389] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 7372.393307] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 7372.401952] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 7372.408545] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x10000:0x0]: rc = 0 [ 7372.415761] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x20000:0x0]: rc = 0 [ 7372.421948] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1010000:0x0]: rc = 0 [ 7372.431926] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x1020000:0x0]: rc = 0 [ 7372.446474] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2010000:0x0]: rc = 0 [ 7372.452632] Lustre: 150381:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0000: backup index [0x200000006:0x2020000:0x0]: rc = 0 [ 7372.722335] Lustre: server umount lustre-MDT0000 complete [ 7375.333863] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 7375.337271] LustreError: Skipped 4 previous similar messages [ 7376.537301] Lustre: Failing over lustre-MDT0001 [ 7376.561910] Lustre: *** cfs_fail_loc=199, val=0*** [ 7376.563933] Lustre: Skipped 53 previous similar messages [ 7376.566250] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000001:0x3:0x0]: rc = 0 [ 7376.572846] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x3:0x0]: rc = 0 [ 7376.579915] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x4:0x0]: rc = 0 [ 7376.586623] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x5:0x0]: rc = 0 [ 7376.592995] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x6:0x0]: rc = 0 [ 7376.599476] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x7:0x0]: rc = 0 [ 7376.603603] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x8:0x0]: rc = 0 [ 7376.608837] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xd:0x0]: rc = 0 [ 7376.615442] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xe:0x0]: rc = 0 [ 7376.622215] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0xf:0x0]: rc = 0 [ 7376.629061] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x10:0x0]: rc = 0 [ 7376.636716] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x11:0x0]: rc = 0 [ 7376.642978] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x12:0x0]: rc = 0 [ 7376.653192] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x13:0x0]: rc = 0 [ 7376.659373] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x14:0x0]: rc = 0 [ 7376.666487] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x15:0x0]: rc = 0 [ 7376.673708] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x16:0x0]: rc = 0 [ 7376.679967] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x17:0x0]: rc = 0 [ 7376.686763] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x18:0x0]: rc = 0 [ 7376.692498] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x19:0x0]: rc = 0 [ 7376.698250] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1a:0x0]: rc = 0 [ 7376.704147] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1b:0x0]: rc = 0 [ 7376.709374] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1c:0x0]: rc = 0 [ 7376.718391] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1d:0x0]: rc = 0 [ 7376.725653] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x1f:0x0]: rc = 0 [ 7376.732382] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x20:0x0]: rc = 0 [ 7376.738648] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x21:0x0]: rc = 0 [ 7376.745485] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x22:0x0]: rc = 0 [ 7376.751127] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x23:0x0]: rc = 0 [ 7376.757605] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x24:0x0]: rc = 0 [ 7376.764309] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x25:0x0]: rc = 0 [ 7376.771296] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x26:0x0]: rc = 0 [ 7376.777190] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x27:0x0]: rc = 0 [ 7376.792396] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x28:0x0]: rc = 0 [ 7376.800260] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x29:0x0]: rc = 0 [ 7376.813662] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2a:0x0]: rc = 0 [ 7376.823921] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2b:0x0]: rc = 0 [ 7376.829303] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2c:0x0]: rc = 0 [ 7376.835732] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2d:0x0]: rc = 0 [ 7376.842218] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2e:0x0]: rc = 0 [ 7376.849217] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000003:0x2f:0x0]: rc = 0 [ 7376.856494] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x1:0x0]: rc = 0 [ 7376.864848] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x2:0x0]: rc = 0 [ 7376.871538] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x3:0x0]: rc = 0 [ 7376.878414] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20001:0x0]: rc = 0 [ 7376.887194] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20002:0x0]: rc = 0 [ 7376.895186] Lustre: 150582:0:(scrub.c:1083:lustre_index_backup()) lustre-MDT0001: backup index [0x200000005:0x20003:0x0]: rc = 0 [ 7377.237965] Lustre: server umount lustre-MDT0001 complete [ 7387.203688] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 7387.309806] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace' with [0x200000003:0x13:0x0]: rc = 0 [ 7387.332528] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 7387.342538] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_03' with [0x200000003:0x28:0x0]: rc = 0 [ 7387.351347] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_04' with [0x200000003:0x18:0x0]: rc = 0 [ 7387.364207] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_14' with [0x200000003:0x33:0x0]: rc = 0 [ 7387.371125] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_04' with [0x200000003:0x29:0x0]: rc = 0 [ 7387.381635] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_06' with [0x200000003:0x1a:0x0]: rc = 0 [ 7387.389595] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_14' with [0x200000003:0x22:0x0]: rc = 0 [ 7387.400583] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_11' with [0x200000003:0x30:0x0]: rc = 0 [ 7387.414990] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_09' with [0x200000003:0x2e:0x0]: rc = 0 [ 7387.429870] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_10' with [0x200000003:0x1e:0x0]: rc = 0 [ 7387.437537] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_05' with [0x200000003:0x2a:0x0]: rc = 0 [ 7387.446870] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_00' with [0x200000003:0x14:0x0]: rc = 0 [ 7387.455958] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_01' with [0x200000003:0x26:0x0]: rc = 0 [ 7387.466342] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_01' with [0x200000003:0x15:0x0]: rc = 0 [ 7387.474331] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_05' with [0x200000003:0x19:0x0]: rc = 0 [ 7387.486979] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_07' with [0x200000003:0x2c:0x0]: rc = 0 [ 7387.498271] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_11' with [0x200000003:0x1f:0x0]: rc = 0 [ 7387.507821] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_15' with [0x200000003:0x23:0x0]: rc = 0 [ 7387.514914] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_09' with [0x200000003:0x1d:0x0]: rc = 0 [ 7387.524337] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_12' with [0x200000003:0x20:0x0]: rc = 0 [ 7387.533433] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_02' with [0x200000003:0x16:0x0]: rc = 0 [ 7387.543601] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_13' with [0x200000003:0x32:0x0]: rc = 0 [ 7387.551795] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_08' with [0x200000003:0x1c:0x0]: rc = 0 [ 7387.557700] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_06' with [0x200000003:0x2b:0x0]: rc = 0 [ 7387.564732] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_07' with [0x200000003:0x1b:0x0]: rc = 0 [ 7387.580360] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_03' with [0x200000003:0x17:0x0]: rc = 0 [ 7387.592635] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_namespace_13' with [0x200000003:0x21:0x0]: rc = 0 [ 7387.603806] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_08' with [0x200000003:0x2d:0x0]: rc = 0 [ 7387.613220] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_02' with [0x200000003:0x27:0x0]: rc = 0 [ 7387.621140] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_00' with [0x200000003:0x25:0x0]: rc = 0 [ 7387.629833] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_15' with [0x200000003:0x34:0x0]: rc = 0 [ 7387.637670] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_10' with [0x200000003:0x2f:0x0]: rc = 0 [ 7387.645970] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'lfsck_layout_12' with [0x200000003:0x31:0x0]: rc = 0 [ 7387.654657] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index 'nodemap' with [0x200000003:0x2:0x0]: rc = 0 [ 7387.662473] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000003:0xc:0x0]: rc = 0 [ 7387.670725] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000003:0xb:0x0]: rc = 0 [ 7387.679616] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000003:0x9:0x0]: rc = 0 [ 7387.687574] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000003:0xa:0x0]: rc = 0 [ 7387.695830] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x20000-MDT0000' with [0x200000005:0x20001:0x0]: rc = 0 [ 7387.706896] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000003:0xd:0x0]: rc = 0 [ 7387.715215] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2010000-MDT0000' with [0x200000005:0x3:0x0]: rc = 0 [ 7387.723608] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000003:0xe:0x0]: rc = 0 [ 7387.732990] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2020000-MDT0000' with [0x200000005:0x20003:0x0]: rc = 0 [ 7387.742881] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1010000-MDT0000' with [0x200000005:0x2:0x0]: rc = 0 [ 7387.750602] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x10000-MDT0000' with [0x200000005:0x1:0x0]: rc = 0 [ 7387.758162] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1020000-MDT0000' with [0x200000005:0x20002:0x0]: rc = 0 [ 7387.765421] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x20000' with [0x200000006:0x20000:0x0]: rc = 0 [ 7387.774553] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1020000' with [0x200000006:0x1020000:0x0]: rc = 0 [ 7387.783531] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2020000' with [0x200000006:0x2020000:0x0]: rc = 0 [ 7387.796857] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x2010000' with [0x200000006:0x2010000:0x0]: rc = 0 [ 7387.807251] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x10000' with [0x200000006:0x10000:0x0]: rc = 0 [ 7387.814520] Lustre: 151079:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0000: restore index '0x1010000' with [0x200000006:0x1010000:0x0]: rc = 0 [ 7401.953442] Lustre: Evicted from MGS (at 192.168.206.105@tcp) after server handle changed from 0x0 to 0xda5f7b36a68025e3 [ 7405.953512] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7414.539083] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7414.604972] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace' with [0x200000003:0xd:0x0]: rc = 0 [ 7414.612112] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'fld' with [0x200000001:0x3:0x0]: rc = 0 [ 7414.617939] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2020000' with [0x200000003:0x8:0x0]: rc = 0 [ 7414.625804] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1020000' with [0x200000003:0x7:0x0]: rc = 0 [ 7414.634853] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x10000' with [0x200000003:0x3:0x0]: rc = 0 [ 7414.641465] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2010000-MDT0001' with [0x200000005:0x3:0x0]: rc = 0 [ 7414.647712] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1010000-MDT0001' with [0x200000005:0x2:0x0]: rc = 0 [ 7414.654727] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x10000-MDT0001' with [0x200000005:0x1:0x0]: rc = 0 [ 7414.661820] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2010000' with [0x200000003:0x5:0x0]: rc = 0 [ 7414.668568] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x20000' with [0x200000003:0x6:0x0]: rc = 0 [ 7414.675589] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x2020000-MDT0001' with [0x200000005:0x20003:0x0]: rc = 0 [ 7414.684519] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1010000' with [0x200000003:0x4:0x0]: rc = 0 [ 7414.693420] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x20000-MDT0001' with [0x200000005:0x20001:0x0]: rc = 0 [ 7414.704345] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index '0x1020000-MDT0001' with [0x200000005:0x20002:0x0]: rc = 0 [ 7414.717205] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_07' with [0x200000003:0x26:0x0]: rc = 0 [ 7414.724152] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_02' with [0x200000003:0x21:0x0]: rc = 0 [ 7414.733572] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_13' with [0x200000003:0x1b:0x0]: rc = 0 [ 7414.750856] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_02' with [0x200000003:0x10:0x0]: rc = 0 [ 7414.760127] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_10' with [0x200000003:0x29:0x0]: rc = 0 [ 7414.770376] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_08' with [0x200000003:0x27:0x0]: rc = 0 [ 7414.778393] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_11' with [0x200000003:0x19:0x0]: rc = 0 [ 7414.791819] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_10' with [0x200000003:0x18:0x0]: rc = 0 [ 7414.803141] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_01' with [0x200000003:0x20:0x0]: rc = 0 [ 7414.815178] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_03' with [0x200000003:0x11:0x0]: rc = 0 [ 7414.822298] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_04' with [0x200000003:0x23:0x0]: rc = 0 [ 7414.831576] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_09' with [0x200000003:0x17:0x0]: rc = 0 [ 7414.840556] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_07' with [0x200000003:0x15:0x0]: rc = 0 [ 7414.852563] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_06' with [0x200000003:0x25:0x0]: rc = 0 [ 7414.866262] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_05' with [0x200000003:0x24:0x0]: rc = 0 [ 7414.876713] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_12' with [0x200000003:0x1a:0x0]: rc = 0 [ 7414.885107] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_01' with [0x200000003:0xf:0x0]: rc = 0 [ 7414.895303] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_00' with [0x200000003:0x1f:0x0]: rc = 0 [ 7414.904066] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_15' with [0x200000003:0x1d:0x0]: rc = 0 [ 7414.915176] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_08' with [0x200000003:0x16:0x0]: rc = 0 [ 7414.931637] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_14' with [0x200000003:0x2d:0x0]: rc = 0 [ 7414.953986] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_09' with [0x200000003:0x28:0x0]: rc = 0 [ 7414.968828] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_04' with [0x200000003:0x12:0x0]: rc = 0 [ 7414.982882] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_03' with [0x200000003:0x22:0x0]: rc = 0 [ 7414.997099] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_06' with [0x200000003:0x14:0x0]: rc = 0 [ 7415.007493] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_12' with [0x200000003:0x2b:0x0]: rc = 0 [ 7415.027441] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_14' with [0x200000003:0x1c:0x0]: rc = 0 [ 7415.056140] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_13' with [0x200000003:0x2c:0x0]: rc = 0 [ 7415.071937] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_05' with [0x200000003:0x13:0x0]: rc = 0 [ 7415.082197] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_namespace_00' with [0x200000003:0xe:0x0]: rc = 0 [ 7415.089509] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_15' with [0x200000003:0x2e:0x0]: rc = 0 [ 7415.099178] Lustre: 151804:0:(osd_scrub.c:1842:osd_index_restore()) lustre-MDT0001: restore index 'lfsck_layout_11' with [0x200000003:0x2a:0x0]: rc = 0 [ 7415.459100] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:105 to 0x280000400:129) [ 7415.464527] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:106 to 0x2c0000400:129) [ 7416.488968] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 7416.489374] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 7418.974572] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7432.433478] Lustre: DEBUG MARKER: == sanity-scrub test 17a: ENOSPC on OI insert shouldn't leak inodes ========================================================== 05:37:02 (1743500222) [ 7433.390205] Lustre: *** cfs_fail_loc=19d, val=0*** [ 7433.392041] Lustre: Skipped 123 previous similar messages [ 7435.016595] Lustre: Failing over lustre-MDT0000 [ 7435.268491] Lustre: server umount lustre-MDT0000 complete [ 7452.058343] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7456.120082] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7457.821059] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:161) [ 7457.824250] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:161) [ 7460.018185] Lustre: DEBUG MARKER: == sanity-scrub test 17b: ENOSPC on .. insertion shouldn't leak inodes ========================================================== 05:37:29 (1743500249) [ 7461.144515] Lustre: *** cfs_fail_loc=19e, val=0*** [ 7462.795853] Lustre: Failing over lustre-MDT0000 [ 7462.882738] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7462.885535] Lustre: Skipped 3 previous similar messages [ 7462.990693] Lustre: server umount lustre-MDT0000 complete [ 7478.797925] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7482.524992] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7484.460529] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:193) [ 7484.460957] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:193) [ 7486.394033] Lustre: DEBUG MARKER: == sanity-scrub test 18: test mount -o resetoi to recreate OI files ========================================================== 05:37:56 (1743500276) [ 7509.499915] Lustre: Failing over lustre-MDT0000 [ 7509.706228] Lustre: server umount lustre-MDT0000 complete [ 7509.987106] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 7509.993414] LustreError: 151094:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 7509.998723] Lustre: Skipped 27 previous similar messages [ 7510.010480] LustreError: 151094:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 55 previous similar messages [ 7512.890990] Lustre: Failing over lustre-MDT0001 [ 7513.110867] Lustre: server umount lustre-MDT0001 complete [ 7520.950889] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 7522.143158] LustreError: 155771:0:(import.c:333:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 7522.148434] LustreError: 155771:0:(import.c:357:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8f7cdfe15c40 x1828185748515200/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1743500314 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_01.0' uid:0 gid:0 [ 7522.164707] LustreError: 155771:0:(import.c:367:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 7526.309775] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7534.642333] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7535.015988] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:193) [ 7535.028223] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:193) [ 7539.106861] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7540.274831] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 7540.275967] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 7545.383168] Lustre: Failing over lustre-MDT0000 [ 7545.584394] Lustre: server umount lustre-MDT0000 complete [ 7549.073457] LustreError: 150172:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743500341 with bad export cookie 15735431097707698664 [ 7549.076386] Lustre: Failing over lustre-MDT0001 [ 7549.083536] LustreError: 150172:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 10 previous similar messages [ 7549.087227] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 7549.098818] LustreError: Skipped 5 previous similar messages [ 7549.401481] Lustre: server umount lustre-MDT0001 complete [ 7558.079368] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 7559.327482] LustreError: 157592:0:(import.c:333:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 7559.330951] LustreError: 157592:0:(import.c:357:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8f7cdd1ad680 x1828185748542848/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1743500351 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 [ 7559.340994] LustreError: 157592:0:(import.c:367:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 7559.650064] Lustre: Evicted from MGS (at 192.168.206.105@tcp) after server handle changed from 0x0 to 0xda5f7b36a680a04e [ 7563.502278] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7566.177123] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1743500342/real 1743500342] req@ffff8f7cdd1aed80 x1828185748543360/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1743500358 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 7566.187675] Lustre: 16277:0:(client.c:2346:ptlrpc_expire_one_request()) Skipped 40 previous similar messages [ 7571.923430] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7572.420202] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:225) [ 7572.423451] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:225) [ 7576.227895] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7577.633323] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:289) [ 7577.634599] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:289) [ 7589.839113] Lustre: DEBUG MARKER: == sanity-scrub test 19: LFSCK can fix multiple linked files on OST ========================================================== 05:39:39 (1743500379) [ 7598.055728] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7598.060093] Lustre: Skipped 3 previous similar messages [ 7603.871749] Lustre: server umount lustre-MDT0000 complete [ 7607.266962] Lustre: server umount lustre-MDT0001 complete [ 7620.301636] Lustre: server umount lustre-OST0000 complete [ 7634.131294] Lustre: server umount lustre-OST0001 complete [ 7639.742755] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 7647.213484] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7664.799540] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 7670.943359] LustreError: 160408:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.105@tcp: failed processing log, type 4: rc = -110 [ 7699.743416] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 7699.746520] Lustre: Skipped 13 previous similar messages [ 7704.888468] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7709.517747] Lustre: Failing over lustre-OST0000 [ 7709.672405] Lustre: server umount lustre-OST0000 complete [ 7715.337131] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 7724.791891] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7741.343603] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 7747.487918] LustreError: 161910:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.105@tcp: failed processing log, type 4: rc = -110 [ 7781.439283] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7791.218775] Lustre: DEBUG MARKER: == sanity-scrub test 20: Don't trigger OI scrub for irreparable oi repeatedly ========================================================== 05:43:01 (1743500581) [ 7806.897167] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 7818.396489] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7818.510329] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7ce0901180 x1828185748604288/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 7818.959613] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:385) [ 7822.664909] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7830.750768] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7830.846461] Lustre: 164327:0:(mgc_request_server.c:553:mgc_llog_local_copy()) MGC192.168.206.105@tcp: no remote llog for lustre-sptlrpc, check MGS config [ 7830.851518] Lustre: 164327:0:(mgc_request_server.c:553:mgc_llog_local_copy()) Skipped 6 previous similar messages [ 7831.108848] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:257) [ 7834.448776] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7837.194088] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 7837.196915] Lustre: Skipped 5 previous similar messages [ 7850.777033] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7852.499610] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:257) [ 7852.515806] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:321) [ 7855.851204] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7863.728264] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 7874.903606] Lustre: *** cfs_fail_loc=193, val=0*** [ 7876.594648] Lustre: Failing over lustre-MDT0000 [ 7876.804741] Lustre: server umount lustre-MDT0000 complete [ 7884.205330] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 7884.437422] Lustre: *** cfs_fail_loc=193, val=0*** [ 7884.439136] Lustre: Skipped 1 previous similar message [ 7884.578362] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 7884.581511] Lustre: Skipped 5 previous similar messages [ 7887.713837] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7889.216972] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 7889.222534] Lustre: Skipped 5 previous similar messages [ 7889.902389] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.206.105@tcp (at 0@lo) [ 7889.907185] Lustre: Skipped 30 previous similar messages [ 7889.927235] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 7889.932607] Lustre: Skipped 5 previous similar messages [ 7889.956539] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:417) [ 7889.958038] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:353) [ 7891.813426] Lustre: *** cfs_fail_loc=19f, val=0*** [ 7891.815419] Lustre: Skipped 52 previous similar messages [ 7891.816853] Lustre: lustre-MDT0000: trigger OI scrub by RPC for [0x200003ab1:0x2:0x0]/16843009 with flags 0x4a: rc = 0 [ 7892.863878] Lustre: *** cfs_fail_loc=19f, val=0*** [ 7892.866219] Lustre: Skipped 5 previous similar messages [ 7907.508670] Lustre: DEBUG MARKER: == sanity-scrub test 21: don't hang MDS recovery when failed to get update log ========================================================== 05:44:57 (1743500697) [ 7909.999114] Lustre: Failing over lustre-MDT0000 [ 7910.231518] Lustre: server umount lustre-MDT0000 complete [ 7913.424515] Lustre: Failing over lustre-MDT0001 [ 7913.676204] Lustre: server umount lustre-MDT0001 complete [ 7916.124332] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 7922.141420] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 7923.295723] LustreError: 168416:0:(import.c:333:ptlrpc_invalidate_import()) MGS: timeout waiting for callback (1 != 0) [ 7923.299884] LustreError: 168416:0:(import.c:357:ptlrpc_invalidate_import()) @@@ still on sending list req@ffff8f7ce0902e40 x1828185748701184/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 1743500715 ref 1 fl Rpc:NQr/200/ffffffff rc 0/-1 job:'ptlrpcd_00_00.0' uid:0 gid:0 [ 7923.311433] LustreError: 168416:0:(import.c:367:ptlrpc_invalidate_import()) MGS: Unregistering RPCs found (0). Network is sluggish? Waiting for them to error out. [ 7923.621217] LustreError: 16274:0:(client.c:1292:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8f7ce0902e40 x1828185748702592/t0(0) o250->MGC192.168.206.105@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl Rpc:NQU/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 7927.805503] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7935.319615] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 7938.662986] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 7941.509373] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:354 to 0x280000401:449) [ 7941.512190] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:385) [ 7941.541040] LustreError: 169163:0:(update_trans.c:1064:top_trans_stop()) lustre-MDT0000-osp-MDT0001: stop trans failed: rc = -20 [ 7941.568639] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:170 to 0x2c0000400:289) [ 7941.570348] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:169 to 0x280000400:289) [ 7942.669359] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 200 [ 7951.358745] Lustre: DEBUG MARKER: == sanity-scrub test 22: LFSCK can recreate or fix the LASTID on MDT/OST ========================================================== 05:45:41 (1743500741) [ 7956.448520] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 7956.451243] Lustre: Skipped 4 previous similar messages [ 7960.559207] Lustre: server umount lustre-MDT0000 complete [ 7963.833402] Lustre: server umount lustre-MDT0001 complete [ 7977.554837] Lustre: server umount lustre-OST0000 complete [ 7990.971826] Lustre: server umount lustre-OST0001 complete [ 7996.944048] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 8006.434536] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8010.323495] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8015.308375] Lustre: Failing over lustre-MDT0000 [ 8015.317848] LustreError: 171510:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 8015.323366] LustreError: 171510:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 8015.328627] LustreError: 171510:0:(lod_dev.c:506:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 9, retries 0, failed: rc = -5 [ 8015.578773] Lustre: server umount lustre-MDT0000 complete [ 8021.001947] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 8032.313502] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 8036.038845] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8045.575803] Lustre: DEBUG MARKER: === sanity-scrub: start setup 05:47:15 (1743500835) === [ 8048.084590] LustreError: 173123:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0001-osp-MDT0000: osp_attr_get update error [0x200000009:0x1:0x0]: rc = -5 [ 8048.090894] LustreError: 173123:0:(lod_sub_object.c:917:lod_sub_prep_llog()) lustre-MDT0000-mdtlov: can't get id from catalogs: rc = -5 [ 8048.095363] LustreError: 173123:0:(lod_dev.c:506:lod_sub_recovery_thread()) lustre-MDT0001-osp-MDT0000: get update log duration 16, retries 0, failed: rc = -5 [ 8048.357707] Lustre: server umount lustre-MDT0000 complete [ 8078.932066] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_hostid [ 8088.413041] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 8102.545812] LDISKFS-fs (vdc): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8112.658709] LDISKFS-fs (vdd): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8120.187273] LDISKFS-fs (vde): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8128.277283] LDISKFS-fs (vdf): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8144.708209] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing load_modules_local [ 8156.520837] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8156.604314] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 8156.895358] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 8156.946949] Lustre: lustre-MDT0000: new disk, initializing [ 8157.046040] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 8160.309509] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8173.166924] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8173.260840] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8173.412824] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 8173.417303] Lustre: Skipped 1 previous similar message [ 8173.487924] Lustre: lustre-MDT0001: new disk, initializing [ 8173.625163] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 8173.634938] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 8177.459522] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8191.371864] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8191.463885] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8191.692431] Lustre: lustre-OST0000: new disk, initializing [ 8191.696818] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 8192.876406] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 8192.889478] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 8193.004669] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 8196.995804] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8209.655566] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro [ 8209.748867] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 8209.877980] Lustre: lustre-OST0001: new disk, initializing [ 8209.882299] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 8211.954202] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 8211.960548] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 8212.052774] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 8215.361248] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 8225.615622] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 8242.104075] Lustre: DEBUG MARKER: === sanity-scrub: finish setup 05:50:31 (1743501031) === [ 8244.176865] Lustre: DEBUG MARKER: == sanity-scrub test complete, duration 7524 sec ========= 05:50:33 (1743501033) [ 8246.366924] Lustre: DEBUG MARKER: === sanity-scrub: start cleanup 05:50:36 (1743501036) === [ 8250.788924] Lustre: DEBUG MARKER: === sanity-scrub: finish cleanup 05:50:40 (1743501040) === [ 8255.456464] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 8255.463375] LustreError: Skipped 10 previous similar messages [ 8255.469501] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 8255.482000] Lustre: Skipped 24 previous similar messages [ 8255.487152] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 8255.489855] Lustre: Skipped 2 previous similar messages [ 8260.768281] Lustre: server umount lustre-MDT0000 complete [ 8263.137046] LustreError: 181299:0:(ldlm_lib.c:1095:target_handle_connect()) lustre-MDT0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 8263.148908] LustreError: 181299:0:(ldlm_lib.c:1095:target_handle_connect()) Skipped 71 previous similar messages [ 8268.243978] LustreError: 181291:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1743501060 with bad export cookie 15735431097707726986 [ 8268.250014] LustreError: MGC192.168.206.105@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 8268.252205] LustreError: 181291:0:(ldlm_lockd.c:2591:ldlm_cancel_handler()) Skipped 11 previous similar messages [ 8268.273887] LustreError: Skipped 4 previous similar messages [ 8268.551834] Lustre: server umount lustre-MDT0001 complete [ 8276.026749] Lustre: server umount lustre-OST0000 complete [ 8283.746323] Lustre: server umount lustre-OST0001 complete [ 8304.834326] Lustre: DEBUG MARKER: oleg605-server.virtnet: executing unload_modules_local [ 8308.263863] Key type lgssc unregistered [ 8308.627671] LNet: 184677:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 8309.669934] LNet: Removed LNI 192.168.206.105@tcp [ 8310.608849] Key type .llcrypt unregistered [ 8310.610762] Key type ._llcrypt unregistered