[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 514673909 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 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524580K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001009] APIC: Switch to symmetric I/O mode setup [ 0.002286] x2apic enabled [ 0.003007] Switched APIC routing to physical x2apic. [ 0.004010] kvm-guest: setup PV IPIs [ 0.006379] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007016] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008008] pid_max: default: 32768 minimum: 301 [ 0.009106] LSM: Security Framework initializing [ 0.010036] Yama: becoming mindful. [ 0.011028] SELinux: Initializing. [ 0.012064] *** VALIDATE selinux *** [ 0.019612] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024032] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.025117] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.026090] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027092] *** VALIDATE tmpfs *** [ 0.028367] *** VALIDATE proc *** [ 0.029196] *** VALIDATE cgroup *** [ 0.030007] *** VALIDATE cgroup2 *** [ 0.032044] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.033125] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.034006] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.035027] Spectre V2 : User space: Vulnerable [ 0.036008] Speculative Store Bypass: Vulnerable [ 0.039127] debug: unmapping init [mem 0xffffffff86659000-0xffffffff86660fff] [ 0.042000] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.042611] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.043019] ... version: 2 [ 0.043995] ... bit width: 48 [ 0.044011] ... generic registers: 4 [ 0.044945] ... value mask: 0000ffffffffffff [ 0.045012] ... max period: 00007fffffffffff [ 0.046009] ... fixed-purpose events: 3 [ 0.047053] ... event mask: 000000070000000f [ 0.048245] rcu: Hierarchical SRCU implementation. [ 0.050402] smp: Bringing up secondary CPUs ... [ 0.051453] x86: Booting SMP configuration: [ 0.052017] .... node #0, CPUs: #1 #2 #3 [ 0.062190] smp: Brought up 1 node, 4 CPUs [ 0.064013] smpboot: Max logical packages: 1 [ 0.065009] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.111083] node 0 deferred pages initialised in 45ms [ 0.113104] devtmpfs: initialized [ 0.114196] x86/mm: Memory block size: 128MB [ 0.117830] gcov: version magic: 0x41383552 [ 0.119095] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.120062] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.121255] pinctrl core: initialized pinctrl subsystem [ 0.122136] [ 0.122573] ************************************************************* [ 0.123011] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.124008] ** ** [ 0.125009] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.126008] ** ** [ 0.127010] ** This means that this kernel is built to expose internal ** [ 0.128007] ** IOMMU data structures, which may compromise security on ** [ 0.129008] ** your system. ** [ 0.130010] ** ** [ 0.131010] ** If you see this message and you are not debugging the ** [ 0.132011] ** kernel, report this immediately to your vendor! ** [ 0.133011] ** ** [ 0.134010] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.135009] ************************************************************* [ 0.136598] NET: Registered protocol family 16 [ 0.137401] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.138053] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.139053] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.140599] cpuidle: using governor menu [ 0.141000] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.144568] PCI: Using configuration type 1 for base access [ 0.146124] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.154465] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.155017] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.158117] cryptd: max_cpu_qlen set to 1000 [ 0.159196] ACPI: Added _OSI(Module Device) [ 0.160009] ACPI: Added _OSI(Processor Device) [ 0.162012] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.163009] ACPI: Added _OSI(Processor Aggregator Device) [ 0.168660] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.175111] ACPI: Interpreter enabled [ 0.177074] ACPI: PM: (supports S0 S3 S4 S5) [ 0.179013] ACPI: Using IOAPIC for interrupt routing [ 0.181248] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.185315] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.202778] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.204076] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.207019] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.210067] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.214479] acpiphp: Slot [2] registered [ 0.216280] acpiphp: Slot [5] registered [ 0.218149] acpiphp: Slot [6] registered [ 0.219329] acpiphp: Slot [7] registered [ 0.221179] acpiphp: Slot [8] registered [ 0.223231] acpiphp: Slot [9] registered [ 0.224166] acpiphp: Slot [10] registered [ 0.226134] acpiphp: Slot [3] registered [ 0.227096] acpiphp: Slot [4] registered [ 0.229117] acpiphp: Slot [11] registered [ 0.231135] acpiphp: Slot [12] registered [ 0.233139] acpiphp: Slot [13] registered [ 0.234170] acpiphp: Slot [14] registered [ 0.236110] acpiphp: Slot [15] registered [ 0.238147] acpiphp: Slot [16] registered [ 0.239000] acpiphp: Slot [17] registered [ 0.239118] acpiphp: Slot [18] registered [ 0.240225] acpiphp: Slot [19] registered [ 0.242204] acpiphp: Slot [20] registered [ 0.244117] acpiphp: Slot [21] registered [ 0.246250] acpiphp: Slot [22] registered [ 0.248157] acpiphp: Slot [23] registered [ 0.250108] acpiphp: Slot [24] registered [ 0.251082] acpiphp: Slot [25] registered [ 0.253103] acpiphp: Slot [26] registered [ 0.255135] acpiphp: Slot [27] registered [ 0.257145] acpiphp: Slot [28] registered [ 0.259114] acpiphp: Slot [29] registered [ 0.261113] acpiphp: Slot [30] registered [ 0.263168] acpiphp: Slot [31] registered [ 0.265077] PCI host bridge to bus 0000:00 [ 0.267019] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.269122] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.272028] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.276022] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.279022] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.282022] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.285054] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.288507] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.292652] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.304925] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.310052] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.313020] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.316025] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.318021] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.320561] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.323945] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.327046] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.330912] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.337016] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.351016] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.358019] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.365659] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.374014] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.389015] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.422014] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.435000] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.451014] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.461016] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.489016] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.506714] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.522012] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.534090] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.562014] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.573900] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.585014] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.596027] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.625019] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.641214] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.651015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.660015] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.687013] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.704434] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.720015] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.729014] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.755014] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.767000] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.770572] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.774869] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.778623] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.782292] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.789163] iommu: Default domain type: Passthrough [ 0.790365] SCSI subsystem initialized [ 0.792183] ACPI: bus type USB registered [ 0.794106] usbcore: registered new interface driver usbfs [ 0.797086] usbcore: registered new interface driver hub [ 0.800081] usbcore: registered new device driver usb [ 0.802177] pps_core: LinuxPPS API ver. 1 registered [ 0.804012] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.808056] PTP clock support registered [ 0.810123] EDAC MC: Ver: 3.0.0 [ 0.812612] PCI: Using ACPI for IRQ routing [ 0.814823] NetLabel: Initializing [ 0.816009] NetLabel: domain hash size = 128 [ 0.818010] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.820077] NetLabel: unlabeled traffic allowed by default [ 0.823174] vgaarb: loaded [ 0.825329] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.827015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.836046] clocksource: Switched to clocksource kvm-clock [ 0.974147] VFS: Disk quotas dquot_6.6.0 [ 0.975713] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.978576] *** VALIDATE ramfs *** [ 0.979903] *** VALIDATE hugetlbfs *** [ 0.982155] pnp: PnP ACPI init [ 0.984532] pnp: PnP ACPI: found 6 devices [ 1.001895] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.005475] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.007815] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.010752] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.013564] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.016389] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 1.020184] NET: Registered protocol family 2 [ 1.022983] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 1.028469] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 1.032314] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 1.038107] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 1.042143] TCP: Hash tables configured (established 65536 bind 65536) [ 1.045723] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 1.049793] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.055180] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 1.058316] NET: Registered protocol family 1 [ 1.063144] RPC: Registered named UNIX socket transport module. [ 1.065426] RPC: Registered udp transport module. [ 1.067566] RPC: Registered tcp transport module. [ 1.071291] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.074117] NET: Registered protocol family 44 [ 1.075915] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.080189] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.082365] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.085714] PCI: CLS 0 bytes, default 64 [ 1.088468] Unpacking initramfs... [ 2.657833] debug: unmapping init [mem 0xffff9b43fcc54000-0xffff9b43fffbffff] [ 2.667750] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.673841] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.678221] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 3.271741] Initialise system trusted keyrings [ 3.273633] Key type blacklist registered [ 3.275952] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 3.287223] zbud: loaded [ 3.290591] *** VALIDATE nfs *** [ 3.292337] *** VALIDATE nfs4 *** [ 3.295117] pstore: using deflate compression [ 3.301313] Platform Keyring initialized [ 3.427663] NET: Registered protocol family 38 [ 3.429625] Key type asymmetric registered [ 3.432372] Asymmetric key parser 'x509' registered [ 3.436414] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.441969] io scheduler mq-deadline registered [ 3.444137] io scheduler kyber registered [ 3.446602] io scheduler bfq registered [ 3.450972] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.454822] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.459628] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.464200] ACPI: Power Button [PWRF] [ 3.473030] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.484168] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.504721] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.518751] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.542775] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.576134] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.608775] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.615757] Non-volatile memory driver v1.3 [ 3.618492] Linux agpgart interface v0.103 [ 3.656394] virtio_blk virtio1: [vda] 150040 512-byte logical blocks (76.8 MB/73.3 MiB) [ 3.660264] vda: detected capacity change from 0 to 76820480 [ 3.679053] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.683162] vdb: detected capacity change from 0 to 1073741824 [ 3.706706] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.711132] vdc: detected capacity change from 0 to 2621440000 [ 3.733109] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.737081] vdd: detected capacity change from 0 to 2621440000 [ 3.768191] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.772625] vde: detected capacity change from 0 to 4294967296 [ 3.807680] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.812623] vdf: detected capacity change from 0 to 4294967296 [ 3.821865] libphy: Fixed MDIO Bus: probed [ 3.835681] usbcore: registered new interface driver usbserial_generic [ 3.839307] usbserial: USB Serial support registered for generic [ 3.843639] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.849706] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.852191] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.856483] mousedev: PS/2 mouse device common for all mice [ 3.862245] rtc_cmos 00:05: RTC can wake from S4 [ 3.867024] rtc_cmos 00:05: registered as rtc0 [ 3.870305] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.873211] intel_pstate: CPU model not supported [ 3.877444] hid: raw HID events driver (C) Jiri Kosina [ 3.881428] usbcore: registered new interface driver usbhid [ 3.883702] usbhid: USB HID core driver [ 3.885661] drop_monitor: Initializing network drop monitor service [ 3.886078] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.892142] Initializing XFRM netlink socket [ 3.897588] NET: Registered protocol family 10 [ 3.900213] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.903850] Segment Routing with IPv6 [ 3.908283] NET: Registered protocol family 17 [ 3.910612] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.912626] mpls_gso: MPLS GSO support [ 3.922645] RAS: Correctable Errors collector initialized. [ 3.925227] AVX version of gcm_enc/dec engaged. [ 3.927052] AES CTR mode by8 optimization enabled [ 4.015683] sched_clock: Marking stable (4015656983, 0)->(4992897220, -977240237) [ 4.021742] registered taskstats version 1 [ 4.025716] Loading compiled-in X.509 certificates [ 4.028491] zswap: loaded using pool lzo/zbud [ 4.059128] Key type big_key registered [ 4.074737] Key type encrypted registered [ 4.077301] ima: No TPM chip found, activating TPM-bypass! [ 4.080417] ima: Allocated hash algorithm: sha1 [ 4.082590] ima: No architecture policies found [ 4.084877] evm: Initialising EVM extended attributes: [ 4.087576] evm: security.selinux [ 4.089259] evm: security.ima [ 4.090644] evm: security.capability [ 4.092610] evm: HMAC attrs: 0x1 [ 4.095767] rtc_cmos 00:05: setting system clock to 2026-09-07 01:52:07 UTC (1788745927) [ 4.102955] debug: unmapping init [mem 0xffffffff87603000-0xffffffff877fffff] [ 4.107487] debug: unmapping init [mem 0xffffffff86382000-0xffffffff86658fff] [ 4.117164] Write protecting the kernel read-only data: 28672k [ 4.120482] debug: unmapping init [mem 0xffffffff84a03000-0xffffffff84bfffff] [ 4.124688] debug: unmapping init [mem 0xffffffff85314000-0xffffffff853fffff] [ 4.165447] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 4.176337] systemd[1]: Detected virtualization kvm. [ 4.178592] systemd[1]: Detected architecture x86-64. [ 4.181128] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 4.207129] systemd[1]: No hostname configured. [ 4.209523] systemd[1]: Set hostname to . [ 4.211954] random: systemd: uninitialized urandom read (16 bytes read) [ 4.215071] systemd[1]: Initializing machine ID from random generator. [ 4.277923] random: ln: uninitialized urandom read (6 bytes read) [ 4.387900] random: systemd: uninitialized urandom read (16 bytes read) [ 4.390498] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 4.396990] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 4.402937] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Initrd Root Device. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Journal Socket. Starting Apply Kernel Variables... [ OK ] Started Memstrack Anylazing Service. Starting Setup Virtual Console... [ OK ] Reached target Timers. [ OK ] Reached target Slices. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. Starting Journal Service... Starting Create Volatile Files and Directories... [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 5.461354] device-mapper: uevent: version 1.0.3 [ 5.464761] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ 6.564970] virtio_net virtio0 ens2: renamed from eth0 [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 6.664927] random: fast init done [ 6.785220] scsi host0: ata_piix [ 6.793376] scsi host1: ata_piix [ 6.796334] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 6.805039] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 11.605549] random: crng init done [ 11.609326] random: 7 urandom warning(s) missed due to ratelimiting [ 12.525549] dracut-initqueue[593]: RTNETLINK answers: File exists Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 13.360423] 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 Remote File Systems. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped target Timers. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Sockets. [ OK ] Stopped target Paths. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped target Swap. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ 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... [ 15.123368] printk: systemd: 26 output lines suppressed due to ratelimiting [ 15.682441] SELinux: Disabled at runtime. [ 15.764413] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 15.781315] systemd[1]: Detected virtualization kvm. [ 15.782968] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 16.756485] systemd[1]: initrd-switch-root.service: Succeeded. [ 16.763567] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 16.775445] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 16.783494] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 16.790308] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 16.802256] systemd[1]: Starting Journal Service... Starting Journal Service... [ 16.813374] systemd[1]: Created slice system-getty.slice. [ OK ] Created slice system-getty.slice. Mounting POSIX Message Queue File System... [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target rpc_pipefs.target. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Activating swap /dev/disk/by-label/SWAP... [ OK ] Created slice User and Session Slice. [ OK ] Stopped target Switch Root. [ OK ] Listening on udev Control Socket. Starting Create list of required st…ce nodes for the current kernel... [ 16.985969] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Kernel Socket. Mounting Kernel Debug File System... Starting udev Coldplug all Devices... [ OK ] Stopped target Initrd File Systems. Mounting Huge Pages File System... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Process Core Dump Socket. Starting Remount Root and Kernel File Systems... Starting Apply Kernel Variables... [ OK ] Reached target Slices. [ OK ] Reached target Paths. [ OK ] Stopped target Initrd Root File System. [ OK ] Started Journal Service. [ 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 ] Mounted Kernel Debug File System. [ OK ] Mounted Huge Pages File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... [ OK ] Reached target Swap. Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... Starting udev Kernel Device Manager... [ OK ] Mounted /mnt. [ 17.900067] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 18.780537] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 18.866101] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 19.193290] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 19.243794] EDAC sbridge: Ver: 1.1.2 [ 22.899919] Key type dns_resolver registered [ 23.306689] NFS: Registering the id_resolver key type [ 23.309591] Key type id_resolver registered [ 23.311707] Key type id_legacy registered [* ] A start job is running for Configur…-only root support (7s / no limit) [ OK ] Started Configure read-only root support. [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Create Volatile Files and Directories... Starting Rebuild Dynamic Linker Cache... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started 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 Restore /run/initramfs on shutdown... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started OpenSSH server daemon. [ OK ] Started Permit User Sessions. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting System Logging Service... Starting Notify NFS peers of a restart... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. [ 32.596016] hrtimer: interrupt took 4018864 ns Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg622-server login: [ 86.740174] libcfs: loading out-of-tree module taints kernel. [ 86.819269] Key type ._llcrypt registered [ 86.822195] Key type .llcrypt registered [ 86.990298] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_hostid [ 107.246097] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 108.996539] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 109.024225] alg: No test for adler32 (adler32-zlib) [ 110.501929] Lustre: Lustre: Build Version: 2.17.58_39_g34d8757 [ 111.403814] LNet: Added LNI 192.168.206.122@tcp [8/256/0/180] [ 113.336233] Key type lgssc registered [ 115.501368] Lustre: Echo OBD driver; http://www.lustre.org/ [ 137.885092] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 181.364547] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 195.547669] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 195.599051] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 197.054318] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 197.117337] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 197.286860] Lustre: lustre-MDT0000: new disk, initializing [ 197.437269] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 197.491508] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 202.673864] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 217.214141] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 217.363685] Lustre: 6520:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 217.401161] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 217.408255] Lustre: Skipped 1 previous similar message [ 217.565395] Lustre: lustre-MDT0001: new disk, initializing [ 217.661900] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 217.693433] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 217.714734] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 222.201260] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 226.831876] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 236.530955] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 236.807954] Lustre: lustre-OST0000: new disk, initializing [ 236.813834] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 236.825341] Lustre: 8457:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 236.947621] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 239.077203] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 239.090393] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 239.169980] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 243.341828] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 259.080166] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 259.234941] Lustre: lustre-OST0001: new disk, initializing [ 259.243274] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 259.251142] Lustre: 9529:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 259.363353] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 265.808096] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 266.819131] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 266.831585] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 266.883419] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 277.519817] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 287.773768] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 296.158357] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing check_logdir /tmp/testlogs/ [ 302.283403] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing yml_node [ 306.856847] Lustre: DEBUG MARKER: Client: 2.17.58.39 [ 309.460441] Lustre: DEBUG MARKER: MDS: 2.17.58.39 [ 312.380446] Lustre: DEBUG MARKER: OSS: 2.17.58.39 [ 314.036363] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Sun Sep 6 21:57:15 EDT 2026 [ 334.763966] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 347.390938] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 355.813622] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 355.823185] 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 [ 355.836850] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 358.882178] 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 [ 358.887134] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 358.900142] Lustre: Skipped 2 previous similar messages [ 358.910617] Lustre: Skipped 2 previous similar messages [ 362.173959] Lustre: server umount lustre-MDT0000 complete [ 369.158330] LustreError: 6531:0:(ldlm_lib.c:1202: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. [ 369.203470] LustreError: 6531:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 8 previous similar messages [ 371.034325] LustreError: 6511:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788746294 with bad export cookie 6790458369461428299 [ 371.042946] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 371.047612] LustreError: 6511:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 371.455520] Lustre: server umount lustre-MDT0001 complete [ 390.496163] Lustre: 3650:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788746297/real 1788746297] req@ffff9b4343824e00 x1875636161458304/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788746313 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 390.539195] 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 [ 391.648618] Lustre: 3653:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788746299/real 1788746299] req@ffff9b4345526d80 x1875636161458560/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788746315 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 391.744277] Lustre: server umount lustre-OST0000 complete [ 394.656228] Lustre: 3650:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788746302/real 1788746302] req@ffff9b4477b47800 x1875636161458816/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788746318 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 396.768911] Lustre: 3653:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788746304/real 1788746304] req@ffff9b4345524700 x1875636161459200/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788746320 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 401.601426] Lustre: server umount lustre-OST0001 complete [ 418.685672] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing unload_modules_local [ 421.938316] Key type lgssc unregistered [ 422.277968] LNet: 14808:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 422.289969] LNetError: 14808:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 423.334807] LNet: Removed LNI 192.168.206.122@tcp [ 424.524135] Key type .llcrypt unregistered [ 424.528784] Key type ._llcrypt unregistered [ 450.691651] Key type ._llcrypt registered [ 450.695790] Key type .llcrypt registered [ 450.846226] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_hostid [ 467.945630] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 469.392793] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 469.609823] alg: No test for adler32 (adler32-zlib) [ 470.751881] Lustre: Lustre: Build Version: 2.17.58_39_g34d8757 [ 471.000575] LNet: Added LNI 192.168.206.122@tcp [8/256/0/180] [ 472.648542] Key type lgssc registered [ 473.682970] Lustre: Echo OBD driver; http://www.lustre.org/ [ 523.544327] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 536.481304] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 536.518046] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 537.985479] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 538.052209] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 538.234984] Lustre: lustre-MDT0000: new disk, initializing [ 538.313328] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 538.330158] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 543.300643] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 558.139532] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 558.275882] Lustre: 19256:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 558.297891] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 558.301587] Lustre: Skipped 1 previous similar message [ 558.365671] Lustre: lustre-MDT0001: new disk, initializing [ 558.423377] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 558.473867] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 558.483435] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 562.501476] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 566.921523] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 575.986467] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 576.282403] Lustre: lustre-OST0000: new disk, initializing [ 576.285673] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 576.290803] Lustre: 21206:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 576.383755] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 582.438778] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 583.741351] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 583.745361] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 583.837123] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 596.016685] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 596.146547] Lustre: lustre-OST0001: new disk, initializing [ 596.150516] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 596.155077] Lustre: 22230:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 596.205052] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 602.651930] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 604.682828] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 604.691861] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 604.755848] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 612.514914] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 617.901548] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 625.713534] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 22:02:27 (1788746547) === [ 628.216686] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 22:02:30 (1788746550) [ 628.528265] Lustre: 19264:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 628.537563] Lustre: 19264:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 628.552355] Lustre: 19264:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 628.558268] Lustre: 19264:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 628.570654] Lustre: 19264:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 628.582238] Lustre: 19264:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 629.046758] Lustre: 19263:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 629.061344] Lustre: 19263:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 14 previous similar messages [ 629.074190] Lustre: 19263:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 629.079312] Lustre: 19263:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 629.087927] Lustre: 19263:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 629.101236] Lustre: 19263:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 629.109308] Lustre: 19263:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 629.115967] Lustre: 19263:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 629.121938] Lustre: 19263:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 629.126548] Lustre: 19263:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 629.131529] Lustre: 19263:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 629.138141] Lustre: 19263:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 14 previous similar messages [ 630.089047] Lustre: 19263:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 630.102992] Lustre: 19263:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 59 previous similar messages [ 630.112822] Lustre: 19263:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 630.117635] Lustre: 19263:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 630.122989] Lustre: 19263:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 630.126704] Lustre: 19263:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 630.131642] Lustre: 19263:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 630.137111] Lustre: 19263:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 630.143549] Lustre: 19263:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 630.152435] Lustre: 19263:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 630.158247] Lustre: 19263:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 630.163979] Lustre: 19263:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 59 previous similar messages [ 632.142341] Lustre: 19264:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 632.158394] Lustre: 19264:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 104 previous similar messages [ 632.169936] Lustre: 19264:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 632.180545] Lustre: 19264:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 632.189835] Lustre: 19264:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 632.200658] Lustre: 19264:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 632.206895] Lustre: 19264:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 632.214923] Lustre: 19264:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 632.220970] Lustre: 19264:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 632.227934] Lustre: 19264:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 632.237571] Lustre: 19264:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 632.243035] Lustre: 19264:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 104 previous similar messages [ 635.550775] Lustre: *** cfs_fail_loc=1600, val=3*** [ 638.809495] Lustre: 21195:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 638.828275] Lustre: 21195:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 99 previous similar messages [ 638.839408] Lustre: 23674:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 638.845098] Lustre: 21195:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 638.845110] Lustre: 21195:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 638.845117] Lustre: 21195:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 638.845120] Lustre: 21195:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 638.845124] Lustre: 21195:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 638.845127] Lustre: 21195:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 638.845132] Lustre: 21195:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 638.845135] Lustre: 21195:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 638.946907] Lustre: 23674:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 106 previous similar messages [ 639.878974] Lustre: *** cfs_fail_loc=1600, val=3*** [ 651.076179] Lustre: 21196:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 651.084301] Lustre: 23682:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 651.088215] Lustre: 21196:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 64 previous similar messages [ 651.088240] Lustre: 21196:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 651.088244] Lustre: 21196:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 651.088249] Lustre: 21196:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 651.088252] Lustre: 21196:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 651.088257] Lustre: 21196:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 651.088260] Lustre: 21196:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 651.088265] Lustre: 21196:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 651.088268] Lustre: 21196:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 64 previous similar messages [ 651.144435] Lustre: 23682:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 58 previous similar messages [ 655.840992] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 655.843137] 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 [ 655.845252] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 655.845252] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 655.880236] Lustre: Skipped 3 previous similar messages [ 659.570346] Lustre: server umount lustre-MDT0000 complete [ 663.035755] LustreError: 19249:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788746586 with bad export cookie 18003336742887458050 [ 663.037657] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 663.045717] LustreError: 19249:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 663.371329] Lustre: server umount lustre-MDT0001 complete [ 677.142633] Lustre: server umount lustre-OST0000 complete [ 690.592303] Lustre: server umount lustre-OST0001 complete [ 698.196299] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 22:03:40 (1788746620) [ 709.967236] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 719.350323] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 719.753811] LustreError: 26287:0:(ldlm_lib.c:1202: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. [ 719.769267] LustreError: 26287:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 5 previous similar messages [ 719.833449] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 724.179684] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 724.961402] LustreError: 26288:0:(ldlm_lib.c:1202: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. [ 730.084165] LustreError: 26287:0:(ldlm_lib.c:1202: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. [ 730.923583] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 731.174799] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 734.983908] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 737.714584] Lustre: 27430:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 742.960712] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 745.316820] LustreError: 27784:0:(ldlm_lib.c:1202:target_handle_connect()) lustre-OST0001: 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. [ 745.325795] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:40 to 0x280000401:65) [ 748.692230] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 750.563203] LustreError: 27786:0:(ldlm_lib.c:1202:target_handle_connect()) lustre-OST0001: 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. [ 756.025224] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 756.246709] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 756.250618] Lustre: Skipped 1 previous similar message [ 761.339566] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 761.481619] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 767.640610] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 770.215239] Lustre: 29300:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 771.399643] Lustre: 26283:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 771.412971] Lustre: 26283:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 771.423703] Lustre: 26283:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 771.436366] Lustre: 26283:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1 previous similar message [ 771.442930] Lustre: 26283:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 771.448949] Lustre: 26283:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1 previous similar message [ 771.455893] Lustre: 26283:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 771.460114] Lustre: 26283:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1 previous similar message [ 771.471025] Lustre: 26283:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 771.477175] Lustre: 26283:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1 previous similar message [ 775.732434] Lustre: *** cfs_fail_loc=1501, val=0*** [ 782.436083] Lustre: Failing over lustre-MDT0000 [ 782.698178] Lustre: server umount lustre-MDT0000 complete [ 786.913136] 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 [ 786.916513] LustreError: 26288:0:(ldlm_lib.c:1202: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. [ 786.926163] Lustre: Skipped 2 previous similar messages [ 786.946081] LustreError: 26288:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 5 previous similar messages [ 791.521473] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 791.616975] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 791.900660] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 791.938882] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 795.827855] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 797.156759] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 797.157655] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 797.206719] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 797.241763] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 797.242135] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 798.726189] Lustre: *** cfs_fail_loc=1505, val=0*** [ 804.663204] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 22:05:26 (1788746726) [ 805.810154] Lustre: 26283:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 805.816139] Lustre: 26283:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 322 previous similar messages [ 805.820480] Lustre: 26283:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 805.825067] Lustre: 26283:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 805.831606] Lustre: 26283:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 805.837157] Lustre: 26283:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 805.842176] Lustre: 26283:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 805.848017] Lustre: 26283:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 805.853310] Lustre: 26283:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 805.858072] Lustre: 26283:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 805.865835] Lustre: 26283:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 805.871543] Lustre: 26283:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 809.965141] Lustre: *** cfs_fail_loc=1502, val=0*** [ 817.296269] Lustre: Failing over lustre-MDT0000 [ 817.485601] Lustre: server umount lustre-MDT0000 complete [ 817.632709] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 817.638881] 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 [ 817.640452] LustreError: 26282:0:(ldlm_lib.c:1202: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. [ 817.665228] Lustre: Skipped 3 previous similar messages [ 826.332385] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 826.474413] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 826.803576] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 830.236092] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 831.961718] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 831.968428] Lustre: lustre-MDT0000: Denying connection for new client d8d41f64-4142-4c79-8418-77e5742b5256 (at 192.168.206.22@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 831.975447] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 831.979362] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 831.987755] Lustre: Skipped 3 previous similar messages [ 832.008407] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 832.009767] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 838.288122] Lustre: *** cfs_fail_loc=1505, val=0*** [ 844.037838] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 22:06:06 (1788746766) [ 849.320135] Lustre: *** cfs_fail_loc=1504, val=0*** [ 849.322282] Lustre: *** cfs_fail_loc=1504, val=0*** [ 849.327474] Lustre: Skipped 1 previous similar message [ 855.615875] Lustre: Failing over lustre-MDT0000 [ 855.744188] Lustre: server umount lustre-MDT0000 complete [ 857.569537] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 857.573329] 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 [ 857.580108] LustreError: 26287:0:(ldlm_lib.c:1202: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. [ 857.589959] Lustre: Skipped 3 previous similar messages [ 857.617382] LustreError: 26287:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 10 previous similar messages [ 864.084972] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 864.173726] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 864.423398] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 864.430093] Lustre: Skipped 1 previous similar message [ 864.470815] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 868.106458] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 869.859491] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 869.872552] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 869.879019] Lustre: Skipped 3 previous similar messages [ 869.907821] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 869.944443] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 869.945298] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 870.924411] Lustre: *** cfs_fail_loc=1505, val=0*** [ 877.230771] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 22:06:39 (1788746799) [ 878.471684] Lustre: 32575:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 878.477217] Lustre: 32575:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 644 previous similar messages [ 878.482676] Lustre: 32575:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 878.488928] Lustre: 32575:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 878.495336] Lustre: 32575:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 878.501889] Lustre: 32575:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 878.508130] Lustre: 32575:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 878.514515] Lustre: 32575:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 878.520976] Lustre: 32575:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 878.526073] Lustre: 32575:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 878.531262] Lustre: 32575:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 878.538919] Lustre: 32575:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 882.874501] Lustre: *** cfs_fail_loc=1603, val=0*** [ 888.343138] Lustre: Failing over lustre-MDT0000 [ 888.570469] Lustre: server umount lustre-MDT0000 complete [ 890.337626] 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 [ 890.348603] Lustre: Skipped 1 previous similar message [ 896.593294] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 896.667988] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 896.890596] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 900.095834] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 901.780742] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 901.785981] Lustre: lustre-MDT0000: Denying connection for new client 9c961b58-abc1-4c5d-9cdf-f6ce19c310f8 (at 192.168.206.22@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 902.118765] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 902.123959] Lustre: Skipped 3 previous similar messages [ 902.138459] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 902.177341] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 902.177382] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 912.388104] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 22:07:14 (1788746834) [ 917.534081] Lustre: *** cfs_fail_loc=1604, val=0*** [ 923.350338] Lustre: Failing over lustre-MDT0000 [ 923.542541] Lustre: server umount lustre-MDT0000 complete [ 927.712534] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 927.719418] 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 [ 927.726398] LustreError: 27036:0:(ldlm_lib.c:1202: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. [ 927.726407] LustreError: 27036:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 12 previous similar messages [ 927.761468] Lustre: Skipped 6 previous similar messages [ 931.316045] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 931.416739] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 931.588945] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 935.068916] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 936.741637] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 936.751672] Lustre: lustre-MDT0000: Denying connection for new client 19530f18-1c6d-411d-93f6-27f00a195ce0 (at 192.168.206.22@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 936.939032] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 936.944952] Lustre: Skipped 3 previous similar messages [ 936.964131] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 937.007958] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 937.008181] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 947.115503] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 22:07:49 (1788746869) [ 952.589448] Lustre: *** cfs_fail_loc=1605, val=0*** [ 958.882362] Lustre: Failing over lustre-MDT0000 [ 959.047246] Lustre: server umount lustre-MDT0000 complete [ 962.529436] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 962.534163] 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 [ 962.558800] Lustre: Skipped 3 previous similar messages [ 967.801471] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 967.911221] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 968.123230] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 971.456874] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 972.955994] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 972.961582] Lustre: lustre-MDT0000: Denying connection for new client 62212a72-59c0-4600-b015-da0698472124 (at 192.168.206.22@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 973.283277] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 973.287616] Lustre: Skipped 3 previous similar messages [ 973.306452] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 973.340818] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 973.343138] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 983.568878] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 22:08:25 (1788746905) [ 988.454657] Lustre: *** cfs_fail_loc=161d, val=0*** [ 994.429790] Lustre: Failing over lustre-MDT0000 [ 994.639332] Lustre: server umount lustre-MDT0000 complete [ 998.883266] 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 [ 998.883662] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 998.901112] Lustre: Skipped 2 previous similar messages [ 1002.135142] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1002.227553] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1002.422951] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1002.426654] Lustre: Skipped 3 previous similar messages [ 1002.460333] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1005.852817] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1007.586323] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1007.587882] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1007.599906] Lustre: Skipped 3 previous similar messages [ 1007.616663] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1007.657106] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 1007.666937] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 1012.499565] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 22:08:54 (1788746934) [ 1013.624740] Lustre: 32575:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 1013.637281] Lustre: 32575:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1290 previous similar messages [ 1013.646325] Lustre: 32575:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 1013.651338] Lustre: 32575:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1290 previous similar messages [ 1013.655598] Lustre: 32575:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1013.659894] Lustre: 32575:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1290 previous similar messages [ 1013.664262] Lustre: 32575:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1013.670939] Lustre: 32575:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1290 previous similar messages [ 1013.679960] Lustre: 32575:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 1013.686218] Lustre: 32575:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1290 previous similar messages [ 1013.691680] Lustre: 32575:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1013.698368] Lustre: 32575:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1290 previous similar messages [ 1014.576218] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1021.576144] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 22:09:04 (1788746944) [ 1026.272933] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1026.975040] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1035.810718] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 22:09:18 (1788746958) [ 1069.805397] Lustre: Failing over lustre-MDT0000 [ 1069.971563] Lustre: server umount lustre-MDT0000 complete [ 1074.146270] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1074.150243] 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 [ 1074.159477] Lustre: Skipped 1 previous similar message [ 1074.166766] LustreError: 26287:0:(ldlm_lib.c:1202: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. [ 1074.178210] LustreError: 26287:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 15 previous similar messages [ 1074.328749] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1081.820806] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1090.460250] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1090.471375] Lustre: lustre-MDT0000: reset Object Index mappings [ 1090.524957] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1090.531304] Lustre: 16422:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788746997/real 1788746997] req@ffff9b445c0f9880 x1875636539520768/t0(0) o400->MGC192.168.206.122@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1788747013 ref 1 fl Rpc:EXNQr/200/ffffffff rc -5/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1090.747870] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1093.673929] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1096.124093] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1096.160675] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1096.171420] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1096.175640] Lustre: Skipped 3 previous similar messages [ 1096.186462] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1096.209170] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1096.210133] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1098.208144] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1098.213380] Lustre: Skipped 1 previous similar message [ 1103.773524] Lustre: Failing over lustre-MDT0000 [ 1103.955751] Lustre: server umount lustre-MDT0000 complete [ 1110.942970] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1114.151652] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1115.603377] Lustre: lustre-MDT0000: Denying connection for new client aa225858-9674-46c7-9d43-57e380587ef5 (at 192.168.206.22@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 1116.684514] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1116.687867] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1121.845764] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1126.357736] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 22:10:48 (1788747048) [ 1128.144340] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1134.921596] Lustre: Failing over lustre-MDT0000 [ 1135.151841] Lustre: server umount lustre-MDT0000 complete [ 1137.126641] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1138.881630] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1145.928118] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1153.506609] Lustre: 16420:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788747060/real 1788747060] req@ffff9b44776cd500 x1875636539606528/t0(0) o400->MGC192.168.206.122@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1788747076 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1153.832856] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1153.858450] Lustre: lustre-MDT0000: reset Object Index mappings [ 1162.721210] LustreError: 16418:0:(client.c:1404:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9b445bcba300 x1875636539615232/t0(0) o250->MGC192.168.206.122@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 projid:4294967295 [ 1163.065766] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1163.077174] Lustre: Skipped 1 previous similar message [ 1166.833890] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1168.355145] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1168.361266] Lustre: Skipped 1 previous similar message [ 1168.361417] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1168.366338] Lustre: Skipped 7 previous similar messages [ 1168.379020] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1168.383620] Lustre: Skipped 1 previous similar message [ 1168.412406] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1168.416148] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1169.709851] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1169.714505] Lustre: Skipped 1 previous similar message [ 1179.388772] Lustre: Failing over lustre-MDT0000 [ 1179.543638] Lustre: server umount lustre-MDT0000 complete [ 1186.704727] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1190.678323] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1192.344305] Lustre: lustre-MDT0000: Denying connection for new client 6cd3015f-bb02-48f3-a95d-6969d9ab417e (at 192.168.206.22@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 1192.460120] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1192.466419] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1198.163123] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1198.166778] Lustre: Skipped 84 previous similar messages [ 1203.359484] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 22:12:05 (1788747125) [ 1209.422875] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1209.425614] Lustre: Skipped 6 previous similar messages [ 1224.735395] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 22:12:27 (1788747147) [ 1230.396761] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1230.402794] Lustre: Skipped 7 previous similar messages [ 1249.958953] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 22:12:52 (1788747172) [ 1263.392744] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1263.397965] Lustre: Skipped 13 previous similar messages [ 1266.289559] Lustre: Failing over lustre-MDT0000 [ 1266.462263] Lustre: server umount lustre-MDT0000 complete [ 1269.216426] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1269.221680] LustreError: Skipped 1 previous similar message [ 1269.225504] 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 [ 1269.239529] Lustre: Skipped 18 previous similar messages [ 1272.807566] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1272.874665] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1272.880472] LustreError: Skipped 3 previous similar messages [ 1273.017649] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1273.021901] Lustre: Skipped 4 previous similar messages [ 1275.539364] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1278.466188] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:854 to 0x280000401:897) [ 1278.466270] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:853 to 0x2c0000401:897) [ 1283.062661] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 22:13:25 (1788747205) [ 1292.377960] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 1304.377500] Lustre: 53153:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1319.806399] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1322.377726] Lustre: 54287:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1323.879888] Lustre: 26283:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1323.890113] Lustre: 26283:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 2024 previous similar messages [ 1323.894297] Lustre: 26283:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1323.905543] Lustre: 26283:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 2025 previous similar messages [ 1323.911874] Lustre: 26283:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1323.921576] Lustre: 26283:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2025 previous similar messages [ 1323.927259] Lustre: 26283:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1323.933912] Lustre: 26283:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 2025 previous similar messages [ 1323.939858] Lustre: 26283:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1323.948063] Lustre: 26283:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2025 previous similar messages [ 1323.955796] Lustre: 26283:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1323.960241] Lustre: 26283:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2025 previous similar messages [ 1328.255348] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1328.264076] Lustre: Skipped 81 previous similar messages [ 1330.397236] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1331.424525] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1332.453063] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1334.029215] Lustre: Failing over lustre-MDT0000 [ 1334.238332] Lustre: server umount lustre-MDT0000 complete [ 1334.757054] LustreError: 27351:0:(ldlm_lib.c:1202: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. [ 1334.766507] LustreError: 27351:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 53 previous similar messages [ 1340.657288] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1340.973563] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1340.978970] Lustre: Skipped 2 previous similar messages [ 1344.216766] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1346.018584] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1346.026885] Lustre: Skipped 2 previous similar messages [ 1346.034330] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1346.042761] Lustre: Skipped 11 previous similar messages [ 1346.055432] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1346.060164] Lustre: Skipped 2 previous similar messages [ 1346.085775] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 1346.089197] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:946 to 0x2c0000401:961) [ 1350.869797] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 22:14:33 (1788747273) [ 1356.257613] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1356.265121] Lustre: Skipped 3 previous similar messages [ 1358.495839] Lustre: server umount lustre-MDT0000 complete [ 1361.284029] LustreError: 29371:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788747284 with bad export cookie 18003336742887670486 [ 1361.301939] LustreError: 29371:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1361.379780] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 1361.389687] Lustre: Skipped 2 previous similar messages [ 1361.552710] Lustre: server umount lustre-MDT0001 complete [ 1370.802823] Lustre: server umount lustre-OST0000 complete [ 1373.392885] Lustre: server umount lustre-OST0001 complete [ 1377.991244] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_hostid [ 1383.398073] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 1413.939813] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 1421.355116] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1421.571257] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1421.594941] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1421.664221] Lustre: lustre-MDT0000: new disk, initializing [ 1421.740472] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1425.387140] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1433.321124] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1433.386929] Lustre: 59347:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1433.412392] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1433.415734] Lustre: Skipped 1 previous similar message [ 1433.480091] Lustre: lustre-MDT0001: new disk, initializing [ 1433.557837] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1433.564630] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1436.204299] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1439.582884] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1443.506591] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1443.633898] Lustre: lustre-OST0000: new disk, initializing [ 1443.636828] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1443.640359] Lustre: 60979:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1445.074156] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1445.079217] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1445.115128] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1447.270315] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1454.694035] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1454.803454] Lustre: lustre-OST0001: new disk, initializing [ 1454.806619] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1454.811305] Lustre: 61848:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1456.798381] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1456.810944] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1456.846521] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1459.259633] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1466.602948] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1469.330655] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1477.026561] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1477.767750] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1477.770907] Lustre: Skipped 19 previous similar messages [ 1480.774706] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1480.779583] Lustre: Skipped 2 previous similar messages [ 1495.970672] Lustre: Failing over lustre-MDT0000 [ 1496.227393] Lustre: server umount lustre-MDT0000 complete [ 1503.692727] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1507.541689] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1509.409581] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1509.418056] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1509.421448] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1514.348025] Lustre: Failing over lustre-MDT0000 [ 1514.474883] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1514.477339] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1514.480510] Lustre: Skipped 2 previous similar messages [ 1514.487619] LustreError: Skipped 2 previous similar messages [ 1514.621154] Lustre: server umount lustre-MDT0000 complete [ 1523.620170] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1528.938547] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1529.385620] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1529.405875] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1529.409290] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1534.638962] Lustre: Failing over lustre-MDT0000 [ 1535.116868] Lustre: server umount lustre-MDT0000 complete [ 1539.557784] 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 [ 1539.568482] Lustre: Skipped 19 previous similar messages [ 1542.650264] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1542.817717] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1542.838177] LustreError: Skipped 4 previous similar messages [ 1547.024726] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1548.296728] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1548.296728] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1551.894859] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1551.898940] Lustre: Skipped 1 previous similar message [ 1562.792505] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 22:18:05 (1788747485) [ 1573.917766] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 1587.531274] Lustre: 68792:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1605.757836] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1701.125958] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 22:20:23 (1788747623) [ 1739.935294] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1739.939402] Lustre: Skipped 4 previous similar messages [ 1758.874023] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1758.877104] Lustre: Skipped 7 previous similar messages [ 1790.276874] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 22:21:52 (1788747712) [ 1828.960430] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1835.884693] Lustre: 59355:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 264, rollback = 2 [ 1835.893469] Lustre: 59355:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 23549 previous similar messages [ 1835.898496] Lustre: 59355:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1835.902745] Lustre: 59355:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 23550 previous similar messages [ 1835.914647] Lustre: 70724:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/264/0 [ 1835.921374] Lustre: 70724:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 23554 previous similar messages [ 1835.929580] Lustre: 70724:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1835.935019] Lustre: 70724:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 23554 previous similar messages [ 1835.942625] Lustre: 70724:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 1835.949893] Lustre: 70724:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 23554 previous similar messages [ 1835.958807] Lustre: 70724:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1835.963516] Lustre: 70724:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 23554 previous similar messages [ 1836.972917] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1836.978486] Lustre: Skipped 532 previous similar messages [ 1852.978752] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1852.983902] Lustre: Skipped 1140 previous similar messages [ 1879.989336] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1879.993797] Lustre: Skipped 2599 previous similar messages [ 2081.223966] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 22:26:43 (1788748003) [ 2224.102683] 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 [ 2224.103890] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2224.104260] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2224.112851] Lustre: Skipped 4 previous similar messages [ 2224.135708] Lustre: Skipped 3 previous similar messages [ 2226.074217] Lustre: server umount lustre-MDT0000 complete [ 2229.223629] LustreError: 70354:0:(ldlm_lib.c:1202: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. [ 2229.250535] LustreError: 70354:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 25 previous similar messages [ 2231.013391] LustreError: 73890:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788748154 with bad export cookie 18003336742887689589 [ 2231.015231] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2231.026223] LustreError: 73890:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2231.480496] Lustre: server umount lustre-MDT0001 complete [ 2245.522682] Lustre: server umount lustre-OST0000 complete [ 2259.623438] Lustre: server umount lustre-OST0001 complete [ 2266.204406] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2274.030367] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2289.632381] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2294.753170] LustreError: 75399:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.122@tcp: failed processing log, type 4: rc = -110 [ 2320.481231] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2320.491829] Lustre: Skipped 8 previous similar messages [ 2328.501460] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2332.515816] Lustre: 75982:0:(ofd_dev.c:563:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2332.544824] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2335.594889] Lustre: 75982:0:(ofd_dev.c:575:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2344.148298] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 22:31:05 (1788748265) [ 2355.969621] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 2365.083171] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2365.485200] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3272 to 0x280000401:3297) [ 2369.406095] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2377.346917] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2381.505301] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2384.520494] Lustre: 78647:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2384.533351] Lustre: 78647:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2398.030382] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2403.321327] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3207 to 0x2c0000401:3233) [ 2403.762616] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2410.572451] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2413.463421] Lustre: 80145:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2417.257871] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2417.784358] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2417.788629] Lustre: Skipped 3 previous similar messages [ 2423.030819] Lustre: Failing over lustre-OST0000 [ 2423.084674] Lustre: server umount lustre-OST0000 complete [ 2430.657569] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2430.836496] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2430.844959] Lustre: Skipped 3 previous similar messages [ 2432.376729] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2432.392488] Lustre: Skipped 3 previous similar messages [ 2432.427214] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2432.429725] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2432.431185] Lustre: *** cfs_fail_loc=215, val=0*** [ 2432.437056] Lustre: Skipped 3 previous similar messages [ 2432.465575] Lustre: Skipped 15 previous similar messages [ 2437.601391] Lustre: *** cfs_fail_loc=215, val=0*** [ 2437.604452] Lustre: Skipped 2 previous similar messages [ 2437.891923] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2441.917280] Lustre: 81543:0:(ofd_dev.c:563:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2441.937173] Lustre: 81543:0:(ofd_dev.c:575:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2442.721143] Lustre: *** cfs_fail_loc=215, val=0*** [ 2442.730267] Lustre: Skipped 1 previous similar message [ 2444.945995] Lustre: Failing over lustre-OST0000 [ 2445.028478] Lustre: server umount lustre-OST0000 complete [ 2453.245224] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2454.842776] Lustre: *** cfs_fail_loc=215, val=0*** [ 2454.845306] Lustre: Skipped 1 previous similar message [ 2458.950618] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2460.134349] Lustre: *** cfs_fail_loc=215, val=0*** [ 2460.141498] Lustre: Skipped 1 previous similar message [ 2464.739820] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2468.835215] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2468.848522] Lustre: Skipped 3 previous similar messages [ 2470.394251] Lustre: server umount lustre-MDT0000 complete [ 2473.885392] LustreError: 75405:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788748397 with bad export cookie 18003336742889252654 [ 2473.899114] LustreError: 75405:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2473.953219] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2473.956595] Lustre: Skipped 1 previous similar message [ 2474.110572] Lustre: server umount lustre-MDT0001 complete [ 2484.107735] Lustre: server umount lustre-OST0000 complete [ 2487.811056] Lustre: server umount lustre-OST0001 complete [ 2494.574574] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 22:33:36 (1788748416) [ 2507.018610] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 2515.686659] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2519.599478] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2526.632220] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2530.865450] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2533.227484] Lustre: 85924:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2538.369368] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2540.721533] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 2543.729657] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2551.215926] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2552.430415] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3207 to 0x2c0000401:3265) [ 2557.002635] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2563.614610] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2566.553409] Lustre: 87795:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2567.506841] Lustre: 84781:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 278, rollback = 2 [ 2567.517337] Lustre: 84781:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 15335 previous similar messages [ 2567.522281] Lustre: 84781:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 2567.530308] Lustre: 84781:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 15335 previous similar messages [ 2567.535050] Lustre: 84781:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2567.539563] Lustre: 84781:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 15331 previous similar messages [ 2567.544776] Lustre: 84781:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2567.551356] Lustre: 84781:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 15331 previous similar messages [ 2567.556923] Lustre: 84781:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 2567.564329] Lustre: 84781:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 15331 previous similar messages [ 2567.568734] Lustre: 84781:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2567.572934] Lustre: 84781:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 15331 previous similar messages [ 2594.375553] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 22:35:16 (1788748516) [ 2606.300573] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 22:35:28 (1788748528) [ 2607.569793] Lustre: *** cfs_fail_loc=160f, val=0*** [ 2616.839845] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 22:35:38 (1788748538) [ 2620.195602] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2620.197960] Lustre: Skipped 3 previous similar messages [ 2670.562726] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2670.580176] Lustre: Skipped 3 previous similar messages [ 2673.357496] Lustre: server umount lustre-MDT0000 complete [ 2676.334711] LustreError: 84767:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788748599 with bad export cookie 18003336742889261110 [ 2676.347672] LustreError: 84767:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2676.552594] Lustre: server umount lustre-MDT0001 complete [ 2690.085897] Lustre: server umount lustre-OST0000 complete [ 2703.016479] Lustre: server umount lustre-OST0001 complete [ 2717.408419] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 2726.929373] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2732.157458] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2740.685822] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2745.123751] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2747.597660] Lustre: 93662:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2753.579660] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2760.004774] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2766.190088] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 2767.513432] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2771.816225] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 2771.850614] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 2771.889051] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 2773.251632] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2779.788199] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2789.109990] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 22:38:31 (1788748711) [ 2793.776637] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2793.791960] Lustre: Skipped 63 previous similar messages [ 2812.897379] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2812.900062] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2812.907290] LustreError: Skipped 3 previous similar messages [ 2812.911381] Lustre: Skipped 2 previous similar messages [ 2827.232121] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 2829.494415] Lustre: server umount lustre-MDT0000 complete [ 2832.927152] LustreError: 92503:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788748756 with bad export cookie 18003336742889289509 [ 2832.931282] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2832.941314] LustreError: 92503:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 2832.951722] LustreError: Skipped 2 previous similar messages [ 2833.202644] Lustre: server umount lustre-MDT0001 complete [ 2847.686539] Lustre: server umount lustre-OST0000 complete [ 2849.506367] Lustre: 16421:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788748756/real 1788748756] req@ffff9b434c086a00 x1875636544091904/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788748772 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2849.533108] 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 [ 2849.548032] Lustre: Skipped 19 previous similar messages [ 2851.327772] Lustre: server umount lustre-OST0001 complete [ 2865.564554] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 2874.071025] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2874.448030] LustreError: 98425:0:(ldlm_lib.c:1202: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. [ 2874.463890] LustreError: 98425:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 45 previous similar messages [ 2878.353436] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2885.107606] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2889.374068] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2891.736532] Lustre: 99566:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2891.742824] Lustre: 99566:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2897.279646] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2899.629819] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 2902.520556] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2908.655821] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2909.809653] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 2909.812095] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 2909.868470] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 2912.804830] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2917.918945] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2924.721147] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 22:40:47 (1788748847) [ 2927.323726] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2927.328065] Lustre: Skipped 63 previous similar messages [ 2927.482958] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2934.639763] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 22:40:56 (1788748856) [ 2936.146095] Lustre: *** cfs_fail_loc=1612, val=0*** [ 2936.208869] Lustre: *** cfs_fail_loc=1612, val=0*** [ 2936.212659] Lustre: Skipped 2 previous similar messages [ 2943.317791] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 22:41:05 (1788748865) [ 2944.290650] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 2945.465561] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 22:41:07 (1788748867) [ 2950.418669] Lustre: *** cfs_fail_loc=1709, val=0*** [ 2950.425221] LustreError: 98434:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240002340:0x6c:0x0]/f60 failed: rc = -5 [ 3008.480591] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3008.484563] Lustre: Skipped 9 previous similar messages [ 3014.775693] Lustre: server umount lustre-MDT0000 complete [ 3020.215375] LustreError: 102962:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788748943 with bad export cookie 18003336742889304237 [ 3020.221524] LustreError: 102962:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3020.433888] Lustre: server umount lustre-MDT0001 complete [ 3035.695638] Lustre: server umount lustre-OST0000 complete [ 3039.010939] Lustre: 16422:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788748946/real 1788748946] req@ffff9b434c086680 x1875636544719360/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788748962 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3041.892959] Lustre: server umount lustre-OST0001 complete [ 3053.187509] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing unload_modules_local [ 3055.225641] Key type lgssc unregistered [ 3055.455702] LNet: 105264:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3055.464156] LNetError: 105264:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3056.485817] LNet: Removed LNI 192.168.206.122@tcp [ 3057.084404] Key type .llcrypt unregistered [ 3057.088439] Key type ._llcrypt unregistered [ 3071.698172] Key type ._llcrypt registered [ 3071.702630] Key type .llcrypt registered [ 3071.793139] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_hostid [ 3080.188197] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 3080.854578] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3080.865877] alg: No test for adler32 (adler32-zlib) [ 3081.835532] Lustre: Lustre: Build Version: 2.17.58_39_g34d8757 [ 3082.015871] LNet: Added LNI 192.168.206.122@tcp [8/256/0/180] [ 3083.650532] Key type lgssc registered [ 3084.327430] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3112.481943] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 3120.276210] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3120.288643] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3121.458374] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3121.482758] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3121.546540] Lustre: lustre-MDT0000: new disk, initializing [ 3121.599312] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3121.610402] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3124.200217] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3132.277114] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3132.348290] Lustre: 109691:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3132.374586] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3132.378295] Lustre: Skipped 1 previous similar message [ 3132.432405] Lustre: lustre-MDT0001: new disk, initializing [ 3132.475845] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3132.492810] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3132.505159] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3135.100936] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3138.725805] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3144.622931] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3144.773511] Lustre: lustre-OST0000: new disk, initializing [ 3144.776219] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3144.780262] Lustre: 111629:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3144.822525] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3148.858223] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3150.336801] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3150.343605] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3150.401407] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3157.957870] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3158.032611] Lustre: lustre-OST0001: new disk, initializing [ 3158.035776] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3158.039812] Lustre: 112653:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3158.089184] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3158.733021] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3158.738638] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3158.787083] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3161.928965] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3169.657859] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3173.489272] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3176.659851] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 22:44:59 (1788749099) === [ 3180.896462] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 22:45:03 (1788749103) [ 3181.085766] Lustre: 110861:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3181.092762] Lustre: 110861:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3181.100250] Lustre: 110861:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3181.109545] Lustre: 110861:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3181.115030] Lustre: 110861:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3181.121184] Lustre: 110861:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3181.592340] Lustre: 109696:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 3181.601799] Lustre: 109696:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 42 previous similar messages [ 3181.609640] Lustre: 109696:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3181.617534] Lustre: 109696:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 42 previous similar messages [ 3181.622690] Lustre: 109696:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3181.629238] Lustre: 109696:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 42 previous similar messages [ 3181.636653] Lustre: 109696:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3181.642134] Lustre: 109696:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 42 previous similar messages [ 3181.650357] Lustre: 109696:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3181.656866] Lustre: 109696:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 42 previous similar messages [ 3181.661882] Lustre: 109696:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3181.671216] Lustre: 109696:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 42 previous similar messages [ 3182.593463] Lustre: 110861:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3182.602685] Lustre: 110861:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 230 previous similar messages [ 3182.624480] Lustre: 109695:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3182.629611] Lustre: 109695:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 233 previous similar messages [ 3182.639451] Lustre: 109695:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3182.644844] Lustre: 109695:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 233 previous similar messages [ 3182.655205] Lustre: 109695:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3182.663752] Lustre: 109695:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 233 previous similar messages [ 3182.670608] Lustre: 109695:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3182.675702] Lustre: 109695:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 233 previous similar messages [ 3182.682533] Lustre: 109695:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3182.687668] Lustre: 109695:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 233 previous similar messages [ 3183.474971] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3190.370972] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 22:45:12 (1788749112) [ 3191.192568] Lustre: 109697:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3191.200070] Lustre: 109697:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 35 previous similar messages [ 3191.205279] Lustre: 109697:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3191.210990] Lustre: 109697:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 3191.216198] Lustre: 109697:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3191.219419] Lustre: 109697:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 3191.224024] Lustre: 109697:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3191.228787] Lustre: 109697:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 3191.236252] Lustre: 109697:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3191.241949] Lustre: 109697:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 3191.247299] Lustre: 109697:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3191.251842] Lustre: 109697:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 32 previous similar messages [ 3192.027633] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3198.679242] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 22:45:21 (1788749121) [ 3198.873155] Lustre: 109696:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3198.877931] Lustre: 109696:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 13 previous similar messages [ 3198.881696] Lustre: 109696:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3198.885484] Lustre: 109696:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 13 previous similar messages [ 3198.890261] Lustre: 109696:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3198.894678] Lustre: 109696:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 13 previous similar messages [ 3198.898258] Lustre: 109696:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3198.902607] Lustre: 109696:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 13 previous similar messages [ 3198.906898] Lustre: 109696:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3198.911335] Lustre: 109696:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 13 previous similar messages [ 3198.916745] Lustre: 109696:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3198.921891] Lustre: 109696:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 13 previous similar messages [ 3200.468142] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3200.471225] Lustre: Skipped 1 previous similar message [ 3213.531345] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3214.520396] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 22:45:37 (1788749137) [ 3214.821849] Lustre: 109696:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3214.830166] Lustre: 109696:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3214.834280] Lustre: 109696:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3214.839177] Lustre: 109696:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3214.842530] Lustre: 109696:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3214.846216] Lustre: 109696:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3214.850414] Lustre: 109696:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3214.857387] Lustre: 109696:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3214.862590] Lustre: 109696:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3214.867530] Lustre: 109696:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3214.875227] Lustre: 109696:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3214.880141] Lustre: 109696:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3216.423470] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3216.493519] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3217.919532] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3217.923451] Lustre: Skipped 5 previous similar messages [ 3230.487687] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 22:45:53 (1788749153) [ 3230.851353] Lustre: 109695:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 264, rollback = 2 [ 3230.863721] Lustre: 109695:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 27 previous similar messages [ 3230.868029] Lustre: 109695:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3230.872236] Lustre: 109695:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3230.879525] Lustre: 109695:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/264/0 [ 3230.884117] Lustre: 109695:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3230.888708] Lustre: 109695:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3230.894174] Lustre: 109695:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3230.898307] Lustre: 109695:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3230.901905] Lustre: 109695:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3230.907115] Lustre: 109695:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3230.911693] Lustre: 109695:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 27 previous similar messages [ 3231.908064] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3231.913557] Lustre: Skipped 5 previous similar messages [ 3265.504890] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3265.514316] 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 [ 3265.523873] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3266.533632] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3266.533707] 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 [ 3266.540723] Lustre: Skipped 2 previous similar messages [ 3266.546946] Lustre: Skipped 2 previous similar messages [ 3270.375777] Lustre: server umount lustre-MDT0000 complete [ 3272.697154] LustreError: 109682:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788749196 with bad export cookie 18044003892583642560 [ 3272.698955] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3272.712295] LustreError: 109682:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3272.879593] Lustre: server umount lustre-MDT0001 complete [ 3285.030726] Lustre: server umount lustre-OST0000 complete [ 3296.779611] Lustre: server umount lustre-OST0001 complete [ 3306.292427] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 3312.679165] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3312.904357] LustreError: 118353:0:(ldlm_lib.c:1202: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. [ 3312.918547] LustreError: 118353:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 5 previous similar messages [ 3312.964130] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3315.808790] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3318.241812] LustreError: 118354:0:(ldlm_lib.c:1202: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. [ 3321.534879] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3321.719591] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3324.379769] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3326.200201] Lustre: 119493:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3330.223870] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3332.456208] LustreError: 119846:0:(ldlm_lib.c:1202:target_handle_connect()) lustre-OST0001: 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. [ 3332.464847] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 3333.742298] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3337.698202] LustreError: 119846:0:(ldlm_lib.c:1202:target_handle_connect()) lustre-OST0001: 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. [ 3338.158112] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3338.268955] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3338.275862] Lustre: Skipped 1 previous similar message [ 3339.301743] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 3339.303916] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 3339.305204] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3341.357387] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3345.838526] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3347.531441] Lustre: 121362:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3354.287034] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 22:47:56 (1788749276) [ 3354.485263] Lustre: 118349:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 3354.492295] Lustre: 118349:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 18 previous similar messages [ 3354.496867] Lustre: 118349:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3354.500730] Lustre: 118349:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3354.506027] Lustre: 118349:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3354.511938] Lustre: 118349:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3354.518382] Lustre: 118349:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3354.523298] Lustre: 118349:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3354.528241] Lustre: 118349:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3354.533121] Lustre: 118349:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3354.537952] Lustre: 118349:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3354.542734] Lustre: 118349:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 18 previous similar messages [ 3355.565769] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3355.568292] Lustre: Skipped 3 previous similar messages [ 3388.386222] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3388.392188] 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 [ 3388.397995] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3388.401427] Lustre: Skipped 1 previous similar message [ 3390.434733] 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 [ 3390.435718] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3390.444352] Lustre: Skipped 1 previous similar message [ 3390.447452] Lustre: Skipped 1 previous similar message [ 3393.355272] Lustre: server umount lustre-MDT0000 complete [ 3395.142984] LustreError: 119095:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788749318 with bad export cookie 18044003892583657806 [ 3395.145283] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3395.148341] LustreError: 119095:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3395.257887] Lustre: server umount lustre-MDT0001 complete [ 3407.242579] Lustre: server umount lustre-OST0000 complete [ 3419.172042] Lustre: server umount lustre-OST0001 complete [ 3426.863385] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 3431.733374] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3431.929051] LustreError: 123945:0:(ldlm_lib.c:1202: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. [ 3431.951542] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3433.725073] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3437.338611] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3439.305755] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3440.699122] Lustre: 125084:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3444.158118] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3447.226274] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3447.396102] LustreError: 125436:0:(ldlm_lib.c:1202:target_handle_connect()) lustre-OST0001: 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. [ 3447.400372] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 3447.410170] LustreError: 125436:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 1 previous similar message [ 3451.474316] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3454.087352] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3456.996081] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 3458.021519] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 3458.022578] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 3463.203240] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3464.753797] Lustre: 126950:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3467.403272] Lustre: 123946:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 3467.408290] Lustre: 123946:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3467.412956] Lustre: 123946:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3467.417610] Lustre: 123946:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3467.421474] Lustre: 123946:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 3467.426277] Lustre: 123946:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3467.430214] Lustre: 123946:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 3467.436599] Lustre: 123946:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3467.440405] Lustre: 123946:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 3467.444025] Lustre: 123946:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3467.448202] Lustre: 123946:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3467.453212] Lustre: 123946:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3467.482178] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3485.348557] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 22:50:08 (1788749408) [ 3486.617520] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3486.619599] Lustre: Skipped 3 previous similar messages [ 3490.755562] Lustre: *** cfs_fail_loc=161c, val=0*** [ 3490.759217] Lustre: Skipped 1 previous similar message [ 3498.991523] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 22:50:21 (1788749421) [ 3499.883673] Lustre: *** cfs_fail_loc=162e, val=0*** [ 3505.668567] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 22:50:28 (1788749428) [ 3507.602460] Lustre: *** cfs_fail_loc=162f, val=0*** [ 3507.604778] Lustre: Skipped 9 previous similar messages [ 3514.479629] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 22:50:37 (1788749437) [ 3520.543790] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 22:50:43 (1788749443) [ 3521.996330] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3522.016821] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3522.020323] Lustre: Skipped 3 previous similar messages [ 3524.949411] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.22@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 10), server csum 70380e72 (type 10) [ 3526.042177] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.22@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 10), server csum 70290e71 (type 10) [ 3529.727332] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 22:50:52 (1788749452) [ 3569.928932] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 22:51:32 (1788749492) [ 3572.664724] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 22:51:35 (1788749495) [ 3578.288228] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 22:51:41 (1788749501) [ 3579.324888] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3579.329311] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3579.331462] Lustre: Skipped 1 previous similar message [ 3584.301679] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 22:51:46 (1788749506) [ 3585.098486] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3585.100854] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3590.428228] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 22:51:53 (1788749513) [ 3591.194677] Lustre: *** cfs_fail_loc=1620, val=0*** [ 3597.537106] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 3598.342270] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 22:52:01 (1788749521) [ 3599.815754] Lustre: 123940:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3599.822666] Lustre: 123940:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 472 previous similar messages [ 3599.826084] Lustre: 123940:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3599.828915] Lustre: 123940:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 472 previous similar messages [ 3599.834071] Lustre: 123940:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3599.840488] Lustre: 123940:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 472 previous similar messages [ 3599.844470] Lustre: 123940:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3599.848359] Lustre: 123940:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 472 previous similar messages [ 3599.852623] Lustre: 123940:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3599.856501] Lustre: 123940:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 472 previous similar messages [ 3599.861387] Lustre: 123940:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3599.866403] Lustre: 123940:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 472 previous similar messages [ 3601.286251] Lustre: *** cfs_fail_loc=1621, val=127*** [ 3601.288436] Lustre: Skipped 1 previous similar message [ 3602.713467] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3617.481096] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 22:52:20 (1788749540) [ 3618.532119] Lustre: Failing over lustre-MDT0000 [ 3618.714526] Lustre: server umount lustre-MDT0000 complete [ 3621.858599] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3621.859791] 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 [ 3621.865403] LustreError: 123946:0:(ldlm_lib.c:1202: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. [ 3621.870913] Lustre: Skipped 4 previous similar messages [ 3621.885457] LustreError: 123946:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 3 previous similar messages [ 3623.161916] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3623.229043] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3623.362627] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3623.366870] Lustre: Skipped 3 previous similar messages [ 3623.393411] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3625.362598] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3627.350474] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3628.520378] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3628.533737] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3628.555220] LustreError: 123942:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 3628.557076] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 3628.557331] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 3633.111766] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 22:52:35 (1788749555) [ 3633.860866] Lustre: *** cfs_fail_loc=1622, val=0*** [ 3633.908810] Lustre: *** cfs_fail_loc=1622, val=0*** [ 3633.911343] Lustre: Skipped 1 previous similar message [ 3638.717780] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 22:52:41 (1788749561) [ 3639.402328] Lustre: *** cfs_fail_loc=1623, val=0*** [ 3643.887147] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 22:52:46 (1788749566) [ 3644.618595] Lustre: *** cfs_fail_loc=1624, val=0*** [ 3649.225970] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 22:52:52 (1788749572) [ 3655.687506] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 22:52:58 (1788749578) [ 3662.457510] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 22:53:05 (1788749585) [ 3663.595882] Lustre: *** cfs_fail_loc=1624, val=0*** [ 3663.599194] Lustre: Skipped 3 previous similar messages [ 3670.080065] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 22:53:12 (1788749592) [ 3673.888390] Lustre: *** cfs_fail_loc=161c, val=0*** [ 3682.236287] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 22:53:24 (1788749604) [ 3689.345414] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 22:53:32 (1788749612) [ 3704.108990] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 22:53:46 (1788749626) [ 3704.869934] Lustre: *** cfs_fail_loc=1626, val=0*** [ 3704.871523] Lustre: Skipped 3 previous similar messages [ 3705.407086] LustreError: 123941:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 3708.605343] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 22:53:51 (1788749631) [ 3735.598652] Lustre: Failing over lustre-MDT0000 [ 3735.796728] Lustre: server umount lustre-MDT0000 complete [ 3736.032960] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3736.033142] 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 [ 3736.034442] LustreError: 123940:0:(ldlm_lib.c:1202: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. [ 3736.034448] LustreError: 123940:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 1 previous similar message [ 3736.051740] Lustre: Skipped 3 previous similar messages [ 3740.740427] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3740.796503] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3740.930965] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3742.783485] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3746.275778] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3746.275879] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3746.287983] Lustre: Skipped 3 previous similar messages [ 3746.300674] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3746.325091] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 3746.325147] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 3751.832693] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 22:54:34 (1788749674) [ 3757.326351] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 22:54:40 (1788749680) [ 3762.647175] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 22:54:45 (1788749685) [ 3763.202476] Lustre: *** cfs_fail_loc=1629, val=0*** [ 3763.204844] Lustre: Skipped 7 previous similar messages [ 3768.267626] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 22:54:51 (1788749691) [ 3770.460507] Lustre: Failing over lustre-MDT0000 [ 3771.873723] 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 [ 3771.874183] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3771.880774] Lustre: Skipped 3 previous similar messages [ 3771.885190] Lustre: Skipped 2 previous similar messages [ 3771.888709] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3776.059147] Lustre: server umount lustre-MDT0000 complete [ 3779.769235] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3779.857676] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3779.972875] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3779.977098] Lustre: Skipped 1 previous similar message [ 3779.994129] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3781.842509] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3782.867206] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3782.871854] Lustre: lustre-MDT0000: Denying connection for new client 13af81f3-839c-4c95-bb51-6867737427bb (at 192.168.206.22@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 3785.187246] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 3785.191488] Lustre: Skipped 3 previous similar messages [ 3785.202808] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 3785.224331] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 3785.224498] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 3791.678494] Lustre: Failing over lustre-MDT0000 [ 3791.882898] Lustre: server umount lustre-MDT0000 complete [ 3795.424811] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3795.567627] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3795.632680] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3795.739415] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 3797.393522] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3798.358852] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3801.060148] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3801.064485] Lustre: Skipped 3 previous similar messages [ 3801.081179] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 3801.109908] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:385) [ 3801.110087] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:227 to 0x2c0000401:257) [ 3804.444411] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 22:55:27 (1788749727) [ 3811.095991] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 22:55:33 (1788749733) [ 3817.618769] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 22:55:40 (1788749740) [ 3851.829331] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 22:56:14 (1788749774) [ 3852.445513] Lustre: *** cfs_fail_loc=162c, val=0*** [ 3852.447363] Lustre: Skipped 13 previous similar messages [ 3857.891411] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 22:56:20 (1788749780) [ 3858.005207] Lustre: 123973:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3858.011359] Lustre: 123973:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 564 previous similar messages [ 3858.016071] Lustre: 123973:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3858.020021] Lustre: 123973:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 564 previous similar messages [ 3858.024385] Lustre: 123973:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3858.030477] Lustre: 123973:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 564 previous similar messages [ 3858.034305] Lustre: 123973:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 3858.038206] Lustre: 123973:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 564 previous similar messages [ 3858.041937] Lustre: 123973:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3858.045747] Lustre: 123973:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 564 previous similar messages [ 3858.049216] Lustre: 123973:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3858.052574] Lustre: 123973:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 564 previous similar messages [ 3862.435537] LustreError: 148670:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 3863.901956] Lustre: Failing over lustre-OST0000 [ 3863.960202] Lustre: server umount lustre-OST0000 complete [ 3865.456053] LustreError: 148670:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 3865.466852] LustreError: lustre-OST0000-osc-MDT0000: operation lfsck_notify to node 0@lo failed: rc = -107 [ 3865.473796] Lustre: lustre-OST0000-osc-MDT0000: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 3865.481276] Lustre: Skipped 4 previous similar messages [ 3865.484839] LustreError: 128447:0:(ldlm_lib.c:1202: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. [ 3865.495252] LustreError: 128447:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 12 previous similar messages [ 3873.887512] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3874.003083] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3875.938043] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 3875.946776] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 3875.946784] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3875.946801] Lustre: Skipped 3 previous similar messages [ 3877.495411] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3882.074630] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 22:56:44 (1788749804) [ 3888.409726] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 3897.349267] Lustre: 151469:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3909.856795] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3916.758351] LustreError: 152714:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 3918.023375] Lustre: Failing over lustre-MDT0001 [ 3918.817079] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 3918.820554] LustreError: Skipped 1 previous similar message [ 3918.822903] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 3918.825170] Lustre: Skipped 1 previous similar message [ 3919.784119] LustreError: 152713:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 3919.789193] LustreError: 152713:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 3919.795102] LustreError: 152713:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 3919.901092] Lustre: server umount lustre-MDT0001 complete [ 3921.256767] LustreError: 152713:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 3928.206122] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 3928.372523] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 3930.024455] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3933.665932] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 3933.667199] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 3933.674065] Lustre: Skipped 1 previous similar message [ 3933.687697] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 3933.721483] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:97) [ 3933.721902] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:97) [ 3933.731242] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 22:57:36 (1788749856) [ 3940.999540] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 3951.394706] Lustre: 155427:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3951.402251] Lustre: 155427:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 3962.853805] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3972.522198] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 22:58:15 (1788749895) [ 3973.156772] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 3973.826468] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 22:58:16 (1788749896) [ 3975.870992] Lustre: *** cfs_fail_loc=1631, val=0*** [ 3984.865163] 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 [ 3984.865238] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3984.865496] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3984.870639] Lustre: Skipped 6 previous similar messages [ 3987.429617] Lustre: server umount lustre-MDT0000 complete [ 3988.786935] LustreError: 143726:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788749912 with bad export cookie 18044003892583730487 [ 3988.788308] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3988.791904] LustreError: 143726:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3988.895707] Lustre: server umount lustre-MDT0001 complete [ 4000.655658] Lustre: server umount lustre-OST0000 complete [ 4012.644322] Lustre: server umount lustre-OST0001 complete [ 4019.301163] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 4023.520468] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4023.694397] LustreError: 159308:0:(ldlm_lib.c:1202: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. [ 4023.703469] LustreError: 159308:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 10 previous similar messages [ 4025.436904] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4028.951407] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4030.894705] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4032.073255] Lustre: 160448:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4032.077993] Lustre: 160448:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 4034.808641] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4037.368293] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4039.010699] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:71 to 0x280000400:129) [ 4040.631203] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4040.709852] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 4040.714838] Lustre: Skipped 6 previous similar messages [ 4043.006302] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4045.794838] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:129) [ 4048.871520] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 4048.874978] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 4051.847587] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4056.828694] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 22:59:39 (1788749979) [ 4057.493679] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 4058.283866] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 22:59:41 (1788749981) [ 4058.988330] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 4059.836529] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 22:59:42 (1788749982) [ 4060.625452] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 4061.557587] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 22:59:44 (1788749984) [ 4066.308351] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 22:59:49 (1788749989) [ 4072.064667] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 22:59:54 (1788749994) [ 4077.469537] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 23:00:00 (1788750000) [ 4083.337307] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 23:00:06 (1788750006) [ 4089.959318] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 23:00:12 (1788750012) [ 4124.643704] Lustre: *** cfs_fail_loc=1632, val=0*** [ 4143.099946] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 23:01:04 (1788750064) [ 4146.132572] Lustre: Failing over lustre-MDT0001 [ 4146.169301] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4146.171296] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4146.186949] Lustre: Skipped 3 previous similar messages [ 4146.201609] Lustre: Skipped 5 previous similar messages [ 4146.460276] Lustre: server umount lustre-MDT0001 complete [ 4154.558331] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4155.172082] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4155.174155] Lustre: lustre-MDT0001: Aborting client recovery [ 4155.196396] LustreError: 166104:0:(ldlm_lib.c:3042:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 4155.209289] Lustre: 166128:0:(ldlm_lib.c:2442:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4155.218691] Lustre: 166128:0:(genops.c:1600:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 2afb955d-ce0f-4df2-891a-dc8c147b0300@ [ 4155.229922] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 4155.243607] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 4155.269042] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 4155.313272] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 4155.323643] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:68 to 0x2c0000400:161) [ 4160.485307] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 4160.519986] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4160.540634] Lustre: Skipped 3 previous similar messages [ 4161.137520] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4164.761836] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 4169.626355] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 4170.026812] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 4178.965209] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 23:01:40 (1788750100) [ 4188.804954] Lustre: *** cfs_fail_loc=1600, val=3*** [ 4193.036894] Lustre: Failing over lustre-MDT0000 [ 4193.693724] Lustre: server umount lustre-MDT0000 complete [ 4195.812399] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4204.334471] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4204.492457] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4204.894194] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4204.906325] Lustre: Skipped 2 previous similar messages [ 4205.913055] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4208.738217] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4210.148531] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4210.153313] Lustre: Skipped 1 previous similar message [ 4210.164560] Lustre: lustre-MDT0000: Recovery over after 0:05, of 2 clients 2 recovered and 0 were evicted. [ 4210.194891] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 4210.195506] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 4215.768272] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 23:02:18 (1788750138) [ 4248.120241] Lustre: Failing over lustre-OST0001 [ 4248.215809] Lustre: server umount lustre-OST0001 complete [ 4252.799812] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: (null) [ 4261.566608] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4262.233493] Lustre: lustre-OST0001: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 4263.609687] Lustre: lustre-OST0001: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 4266.413459] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4271.800521] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 4272.028916] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 4275.816926] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 4276.007771] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 4280.790908] Lustre: DEBUG MARKER: oleg622-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff96885236d800.ost_server_uuid 50 [ 4282.081738] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff96885236d800.ost_server_uuid in FULL state after 0 sec [ 4348.900908] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4348.908595] Lustre: Skipped 1 previous similar message [ 4355.112177] Lustre: server umount lustre-MDT0000 complete [ 4359.140989] LustreError: 159303:0:(ldlm_lib.c:1202: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. [ 4359.167851] LustreError: 159303:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 29 previous similar messages [ 4361.939504] LustreError: 160051:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788750285 with bad export cookie 18044003892583813059 [ 4361.940411] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4361.954116] LustreError: 160051:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 4362.259385] Lustre: server umount lustre-MDT0001 complete [ 4380.417093] Lustre: server umount lustre-OST0000 complete [ 4380.451787] Lustre: 106854:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788750287/real 1788750287] req@ffff9b434a22ca80 x1875639278451072/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788750303 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4381.665747] Lustre: 106853:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788750289/real 1788750289] req@ffff9b4448526680 x1875639278451328/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788750305 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4384.608730] Lustre: 106854:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788750292/real 1788750292] req@ffff9b434a22df80 x1875639278451584/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788750308 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4387.969920] Lustre: server umount lustre-OST0001 complete [ 4402.303582] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing unload_modules_local [ 4404.861077] Key type lgssc unregistered [ 4405.148226] LNet: 175786:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 4405.158915] LNetError: 175786:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 4406.185455] LNet: Removed LNI 192.168.206.122@tcp [ 4407.101139] Key type .llcrypt unregistered [ 4407.107773] Key type ._llcrypt unregistered [ 4427.739220] Key type ._llcrypt registered [ 4427.741919] Key type .llcrypt registered [ 4427.828352] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_hostid [ 4442.873414] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 4443.681765] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 4443.798048] alg: No test for adler32 (adler32-zlib) [ 4444.880385] Lustre: Lustre: Build Version: 2.17.58_39_g34d8757 [ 4445.170827] LNet: Added LNI 192.168.206.122@tcp [8/256/0/180] [ 4446.864250] Key type lgssc registered [ 4447.889637] Lustre: Echo OBD driver; http://www.lustre.org/ [ 4494.195607] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing load_modules_local [ 4507.018606] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 4507.051918] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4508.326174] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 4508.365110] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 4508.423395] Lustre: lustre-MDT0000: new disk, initializing [ 4508.484784] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4508.498618] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 4512.875609] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4527.255042] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4527.410727] Lustre: 180236:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 4527.458670] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 4527.470579] Lustre: Skipped 1 previous similar message [ 4527.557226] Lustre: lustre-MDT0001: new disk, initializing [ 4527.624193] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4527.678723] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 4527.698832] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 4533.216441] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4538.126908] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 4546.415034] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4546.683717] Lustre: lustre-OST0000: new disk, initializing [ 4546.689411] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 4546.699219] Lustre: 182173:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4546.782017] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4552.261642] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 4552.274846] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 4552.355162] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 4553.084683] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4568.075874] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4568.217903] Lustre: lustre-OST0001: new disk, initializing [ 4568.221356] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 4568.226497] Lustre: 183199:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 4568.283922] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 4573.893772] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4577.305465] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 4577.317205] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 4577.382599] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 4584.080370] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4592.167561] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 4599.855368] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 23:08:41 (1788750521) === [ 4601.793762] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 4286 sec ========= 23:08:43 (1788750523) [ 4603.564726] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 23:08:45 (1788750525) === [ 4607.134389] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 23:08:48 (1788750528) === [ 4613.091118] 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 [ 4613.101989] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4613.108273] Lustre: Skipped 1 previous similar message [ 4613.123325] Lustre: Skipped 3 previous similar messages [ 4620.226531] Lustre: server umount lustre-MDT0000 complete [ 4623.329665] LustreError: 180248:0:(ldlm_lib.c:1202: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. [ 4623.349644] LustreError: 180248:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 8 previous similar messages [ 4628.456972] LustreError: 180247:0:(ldlm_lib.c:1202: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. [ 4628.490244] LustreError: 180247:0:(ldlm_lib.c:1202:target_handle_connect()) Skipped 3 previous similar messages [ 4628.522992] LustreError: 183197:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788750551 with bad export cookie 8270595016557204347 [ 4628.530694] LustreError: MGC192.168.206.122@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4628.539307] LustreError: 183197:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4628.840680] Lustre: server umount lustre-MDT0001 complete [ 4648.651780] Lustre: server umount lustre-OST0000 complete [ 4648.737279] Lustre: 177397:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788750556/real 1788750556] req@ffff9b434a22ce00 x1875640705958656/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788750572 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4648.766025] 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 [ 4648.781850] Lustre: Skipped 2 previous similar messages [ 4654.051239] Lustre: 177395:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788750561/real 1788750561] req@ffff9b445b181c00 x1875640705959040/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788750577 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4655.073176] Lustre: 177396:0:(client.c:2504:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788750562/real 1788750562] req@ffff9b434dcf0a80 x1875640705959296/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788750578 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4656.550276] Lustre: server umount lustre-OST0001 complete [ 4670.755638] Lustre: DEBUG MARKER: oleg622-server.virtnet: executing unload_modules_local [ 4673.086203] Key type lgssc unregistered [ 4673.319790] LNet: 186671:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 4673.326162] LNetError: 186671:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 4673.338058] LNet: Removed LNI 192.168.206.122@tcp [ 4674.096141] Key type .llcrypt unregistered [ 4674.099473] Key type ._llcrypt unregistered