[ 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 485547014 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, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001011] APIC: Switch to symmetric I/O mode setup [ 0.003142] x2apic enabled [ 0.004008] Switched APIC routing to physical x2apic. [ 0.005013] kvm-guest: setup PV IPIs [ 0.007609] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008017] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.010012] pid_max: default: 32768 minimum: 301 [ 0.011125] LSM: Security Framework initializing [ 0.012044] Yama: becoming mindful. [ 0.013033] SELinux: Initializing. [ 0.014050] *** VALIDATE selinux *** [ 0.021484] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.025264] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.026120] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028054] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.029085] *** VALIDATE tmpfs *** [ 0.031141] *** VALIDATE proc *** [ 0.032210] *** VALIDATE cgroup *** [ 0.033005] *** VALIDATE cgroup2 *** [ 0.034243] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.035136] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.036006] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037023] Spectre V2 : User space: Vulnerable [ 0.038009] Speculative Store Bypass: Vulnerable [ 0.040834] debug: unmapping init [mem 0xffffffff99e59000-0xffffffff99e60fff] [ 0.043197] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044568] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045022] ... version: 2 [ 0.046009] ... bit width: 48 [ 0.047008] ... generic registers: 4 [ 0.048010] ... value mask: 0000ffffffffffff [ 0.049015] ... max period: 00007fffffffffff [ 0.050013] ... fixed-purpose events: 3 [ 0.051012] ... event mask: 000000070000000f [ 0.052270] rcu: Hierarchical SRCU implementation. [ 0.054362] smp: Bringing up secondary CPUs ... [ 0.055542] x86: Booting SMP configuration: [ 0.056020] .... node #0, CPUs: #1 #2 #3 [ 0.059195] smp: Brought up 1 node, 4 CPUs [ 0.060994] smpboot: Max logical packages: 1 [ 0.061014] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.144666] node 0 deferred pages initialised in 82ms [ 0.148105] devtmpfs: initialized [ 0.150357] x86/mm: Memory block size: 128MB [ 0.153746] gcov: version magic: 0x41383552 [ 0.156290] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.159070] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.161253] pinctrl core: initialized pinctrl subsystem [ 0.163166] [ 0.163717] ************************************************************* [ 0.166011] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.168009] ** ** [ 0.171009] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.173009] ** ** [ 0.175009] ** This means that this kernel is built to expose internal ** [ 0.177011] ** IOMMU data structures, which may compromise security on ** [ 0.179009] ** your system. ** [ 0.181011] ** ** [ 0.183009] ** If you see this message and you are not debugging the ** [ 0.184009] ** kernel, report this immediately to your vendor! ** [ 0.186010] ** ** [ 0.188017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.190010] ************************************************************* [ 0.192436] NET: Registered protocol family 16 [ 0.195454] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.198057] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.202062] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.206023] cpuidle: using governor menu [ 0.207817] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.211460] PCI: Using configuration type 1 for base access [ 0.213119] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.222118] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.224029] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.228072] cryptd: max_cpu_qlen set to 1000 [ 0.231217] ACPI: Added _OSI(Module Device) [ 0.233016] ACPI: Added _OSI(Processor Device) [ 0.234011] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.236013] ACPI: Added _OSI(Processor Aggregator Device) [ 0.240072] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.247056] ACPI: Interpreter enabled [ 0.248067] ACPI: PM: (supports S0 S3 S4 S5) [ 0.250015] ACPI: Using IOAPIC for interrupt routing [ 0.251198] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.255613] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.267441] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.270052] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.273021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.276063] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.280199] acpiphp: Slot [2] registered [ 0.281103] acpiphp: Slot [5] registered [ 0.282102] acpiphp: Slot [6] registered [ 0.283083] acpiphp: Slot [7] registered [ 0.285056] acpiphp: Slot [8] registered [ 0.286087] acpiphp: Slot [9] registered [ 0.287102] acpiphp: Slot [10] registered [ 0.288081] acpiphp: Slot [3] registered [ 0.289076] acpiphp: Slot [4] registered [ 0.290077] acpiphp: Slot [11] registered [ 0.292093] acpiphp: Slot [12] registered [ 0.294162] acpiphp: Slot [13] registered [ 0.295121] acpiphp: Slot [14] registered [ 0.297114] acpiphp: Slot [15] registered [ 0.298088] acpiphp: Slot [16] registered [ 0.299082] acpiphp: Slot [17] registered [ 0.301109] acpiphp: Slot [18] registered [ 0.302090] acpiphp: Slot [19] registered [ 0.303162] acpiphp: Slot [20] registered [ 0.304091] acpiphp: Slot [21] registered [ 0.306129] acpiphp: Slot [22] registered [ 0.307090] acpiphp: Slot [23] registered [ 0.308068] acpiphp: Slot [24] registered [ 0.309074] acpiphp: Slot [25] registered [ 0.310075] acpiphp: Slot [26] registered [ 0.311101] acpiphp: Slot [27] registered [ 0.312057] acpiphp: Slot [28] registered [ 0.314084] acpiphp: Slot [29] registered [ 0.315099] acpiphp: Slot [30] registered [ 0.317087] acpiphp: Slot [31] registered [ 0.318054] PCI host bridge to bus 0000:00 [ 0.319015] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.321017] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.323019] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.326020] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.328016] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.330021] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.332171] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.334953] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.338190] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.348014] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.352060] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.355018] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.357018] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.362018] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.364475] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.368630] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.373041] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.375713] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.380013] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.392014] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.398013] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.402514] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.409013] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.414014] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.429014] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.442093] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.451015] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.461014] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.477017] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.487704] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.496014] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.503014] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.517030] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.528016] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.537011] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.544013] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.562020] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.576382] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.583015] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.593018] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.609016] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.623071] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.629013] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.641013] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.669015] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.680537] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.684550] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.687585] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.691393] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.694220] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.698115] iommu: Default domain type: Passthrough [ 0.700381] SCSI subsystem initialized [ 0.702111] ACPI: bus type USB registered [ 0.704200] usbcore: registered new interface driver usbfs [ 0.706086] usbcore: registered new interface driver hub [ 0.708062] usbcore: registered new device driver usb [ 0.709111] pps_core: LinuxPPS API ver. 1 registered [ 0.710007] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.713071] PTP clock support registered [ 0.715133] EDAC MC: Ver: 3.0.0 [ 0.717099] PCI: Using ACPI for IRQ routing [ 0.719964] NetLabel: Initializing [ 0.722010] NetLabel: domain hash size = 128 [ 0.723011] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.725085] NetLabel: unlabeled traffic allowed by default [ 0.728257] vgaarb: loaded [ 0.729296] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.732014] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.741000] clocksource: Switched to clocksource kvm-clock [ 0.846683] VFS: Disk quotas dquot_6.6.0 [ 0.848091] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.850688] *** VALIDATE ramfs *** [ 0.852442] *** VALIDATE hugetlbfs *** [ 0.854071] pnp: PnP ACPI init [ 0.856596] pnp: PnP ACPI: found 6 devices [ 0.879515] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.883913] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.886672] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.889112] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.892574] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.895757] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.899522] NET: Registered protocol family 2 [ 0.902663] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.908974] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.912995] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.918365] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.921922] TCP: Hash tables configured (established 65536 bind 65536) [ 0.925140] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.928642] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.931760] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.935045] NET: Registered protocol family 1 [ 0.938203] RPC: Registered named UNIX socket transport module. [ 0.940606] RPC: Registered udp transport module. [ 0.942181] RPC: Registered tcp transport module. [ 0.943965] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.946391] NET: Registered protocol family 44 [ 0.948665] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.952506] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.955623] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.957964] PCI: CLS 0 bytes, default 64 [ 0.959806] Unpacking initramfs... [ 2.346042] debug: unmapping init [mem 0xffff8bb4bcc54000-0xffff8bb4bffbffff] [ 2.350366] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.352906] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.355966] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.834304] Initialise system trusted keyrings [ 2.835994] Key type blacklist registered [ 2.837567] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.846592] zbud: loaded [ 2.849607] *** VALIDATE nfs *** [ 2.850914] *** VALIDATE nfs4 *** [ 2.852522] pstore: using deflate compression [ 2.857303] Platform Keyring initialized [ 2.987604] NET: Registered protocol family 38 [ 2.988892] Key type asymmetric registered [ 2.991014] Asymmetric key parser 'x509' registered [ 2.993022] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.997627] io scheduler mq-deadline registered [ 3.000499] io scheduler kyber registered [ 3.002303] io scheduler bfq registered [ 3.004538] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.007703] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.010165] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.012635] ACPI: Power Button [PWRF] [ 3.017518] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.023847] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.039029] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.043932] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.054503] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.080619] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.111232] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.117988] Non-volatile memory driver v1.3 [ 3.119225] Linux agpgart interface v0.103 [ 3.145677] virtio_blk virtio1: [vda] 145904 512-byte logical blocks (74.7 MB/71.2 MiB) [ 3.147968] vda: detected capacity change from 0 to 74702848 [ 3.161641] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.164714] vdb: detected capacity change from 0 to 1073741824 [ 3.183978] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.188204] vdc: detected capacity change from 0 to 2621440000 [ 3.205866] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.209694] vdd: detected capacity change from 0 to 2621440000 [ 3.223338] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.226129] vde: detected capacity change from 0 to 4294967296 [ 3.242880] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.245328] vdf: detected capacity change from 0 to 4294967296 [ 3.252286] libphy: Fixed MDIO Bus: probed [ 3.262893] usbcore: registered new interface driver usbserial_generic [ 3.266892] usbserial: USB Serial support registered for generic [ 3.270848] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.277719] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.280223] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.283703] mousedev: PS/2 mouse device common for all mice [ 3.289023] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.292420] rtc_cmos 00:05: RTC can wake from S4 [ 3.296100] rtc_cmos 00:05: registered as rtc0 [ 3.296803] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.298668] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.303873] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.304215] intel_pstate: CPU model not supported [ 3.307370] hid: raw HID events driver (C) Jiri Kosina [ 3.314659] usbcore: registered new interface driver usbhid [ 3.316852] usbhid: USB HID core driver [ 3.318553] drop_monitor: Initializing network drop monitor service [ 3.320923] Initializing XFRM netlink socket [ 3.323366] NET: Registered protocol family 10 [ 3.326341] Segment Routing with IPv6 [ 3.327775] NET: Registered protocol family 17 [ 3.330032] mpls_gso: MPLS GSO support [ 3.334923] RAS: Correctable Errors collector initialized. [ 3.337022] AVX version of gcm_enc/dec engaged. [ 3.338849] AES CTR mode by8 optimization enabled [ 3.440672] sched_clock: Marking stable (3440647473, 0)->(4277053411, -836405938) [ 3.445338] registered taskstats version 1 [ 3.447929] Loading compiled-in X.509 certificates [ 3.450056] zswap: loaded using pool lzo/zbud [ 3.481890] Key type big_key registered [ 3.500129] Key type encrypted registered [ 3.502417] ima: No TPM chip found, activating TPM-bypass! [ 3.505531] ima: Allocated hash algorithm: sha1 [ 3.507834] ima: No architecture policies found [ 3.509981] evm: Initialising EVM extended attributes: [ 3.512618] evm: security.selinux [ 3.514395] evm: security.ima [ 3.515783] evm: security.capability [ 3.517522] evm: HMAC attrs: 0x1 [ 3.520816] rtc_cmos 00:05: setting system clock to 2026-08-15 21:11:21 UTC (1786828281) [ 3.529912] debug: unmapping init [mem 0xffffffff9ae03000-0xffffffff9affffff] [ 3.533965] debug: unmapping init [mem 0xffffffff99b82000-0xffffffff99e58fff] [ 3.543269] Write protecting the kernel read-only data: 28672k [ 3.547818] debug: unmapping init [mem 0xffffffff98203000-0xffffffff983fffff] [ 3.550800] debug: unmapping init [mem 0xffffffff98b14000-0xffffffff98bfffff] [ 3.587848] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 3.597337] systemd[1]: Detected virtualization kvm. [ 3.599502] systemd[1]: Detected architecture x86-64. [ 3.601747] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.628277] systemd[1]: No hostname configured. [ 3.630143] systemd[1]: Set hostname to . [ 3.632145] random: systemd: uninitialized urandom read (16 bytes read) [ 3.634693] systemd[1]: Initializing machine ID from random generator. [ 3.778625] random: systemd: uninitialized urandom read (16 bytes read) [ 3.782534] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 3.787936] random: systemd: uninitialized urandom read (16 bytes read) [ 3.790830] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 3.798282] systemd[1]: Reached target Timers. [ OK ] Reached target Timers. [ OK ] Listening on udev Control Socket. [ OK ] Reached target Slices. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Reached target Initrd Root Device. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Sockets. Starting Setup Virtual Console... [ OK ] Started Memstrack Anylazing Service. [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... Starting Apply Kernel Variables... Starting Journal Service... [ OK ] Reached target Paths. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Setup Virtual Console. [ OK ] Started Create Volatile Files and Directories. [ OK ] Started Apply Kernel Variables. Starting dracut cmdline hook... Starting Create Static Device Nodes in /dev... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.581197] device-mapper: uevent: version 1.0.3 [ 4.585518] 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. [ 6.268464] random: fast init done [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting dracut initqueue hook... [ 6.401492] virtio_net virtio0 ens2: renamed from eth0 [ 6.658125] scsi host0: ata_piix [ 6.692359] scsi host1: ata_piix [ 6.702134] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 6.713311] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 11.024097] random: crng init done [ 11.025403] random: 7 urandom warning(s) missed due to ratelimiting [ 12.048098] dracut-initqueue[587]: 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.086399] EXT4-fs (nbd0): mounted filesystem with ordered data mode. Opts: (null) [ OK ] Mounted /sysroot. [ OK ] Reached target Initrd Root File System. Starting Reload Configuration from the Real Root... [ OK ] Started Reload Configuration from the Real Root. [ OK ] Reached target Initrd File Systems. [ OK ] Reached target Initrd Default Target. Starting dracut pre-pivot and cleanup hook... [ OK ] Started dracut pre-pivot and cleanup hook. Starting Cleaning Up and Shutting Down Daemons... [ OK ] Stopped target Timers. [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped target Swap. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Stopped target Paths. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped target Sockets. [ 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 Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 16.669087] printk: systemd: 26 output lines suppressed due to ratelimiting [ 17.536817] SELinux: Disabled at runtime. [ 17.687749] 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) [ 17.707736] systemd[1]: Detected virtualization kvm. [ 17.717555] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 19.633219] systemd[1]: initrd-switch-root.service: Succeeded. [ 19.648932] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 19.685364] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 19.698907] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 19.709916] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 19.755161] systemd[1]: Starting Journal Service... Starting Journal Service... [ 19.767355] systemd[1]: Stopped target Switch Root. [ OK ] Stopped target Switch Root. Mounting Kernel Debug File System... [ OK ] Stopped target Initrd File Systems. [ OK ] Created slice system-serial\x2dgetty.slice. Starting Remount Root and Kernel File Systems... [ OK ] Listening on Process Core Dump Socket. Starting Apply Kernel Variables... [ OK ] Created slice User and Session Slice. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Listening on udev Kernel Socket. [ OK ] Reached target Slices. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. Mounting Huge Pages File System... [ OK ] Stopped target Initrd Root File System. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting POSIX Message Queue File System... [ OK ] Created slice system-getty.slice. [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on udev Control Socket. [ OK ] Listening on initctl Compatibility Named Pipe. Activating swap /dev/disk/by-label/SWAP... [ OK ] Created slice system-sshd\x2dkeygen.slice. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target rpc_pipefs.target. [ 20.379706] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS Starting udev Coldplug all Devices... [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Started Apply Kernel Variables. [ OK ] Mounted Huge Pages File System. [ 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 ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 21.108954] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 21.756974] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 21.837317] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 22.214169] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 22.388546] EDAC sbridge: Ver: 1.1.2 [ 26.245870] Key type dns_resolver registered [ 26.620420] NFS: Registering the id_resolver key type [ 26.622635] Key type id_resolver registered [ 26.624444] 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. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. Starting Mark the need to relabel after reboot... Starting Rebuild Dynamic Linker Cache... Starting Create Volatile Files and Directories... [ OK ] Started Load/Save Random Seed. [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. Starting Login Service... Starting Restore /run/initramfs on shutdown... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started irqbalance daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting GSSAPI Proxy Daemon... Starting OpenSSH server daemon... Starting Network Manager Wait Online... Starting Hostname Service... [ OK ] Started OpenSSH server daemon. [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting Crash recovery kernel arming... Starting Notify NFS peers of a restart... Starting System Logging Service... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. [ 34.939315] hrtimer: interrupt took 3305023 ns Starting Authorization Manager... [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg604-server login: [ 82.876367] libcfs: loading out-of-tree module taints kernel. [ 82.920951] Key type ._llcrypt registered [ 82.925421] Key type .llcrypt registered [ 83.032674] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_hostid [ 99.858923] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 101.484743] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 101.505269] alg: No test for adler32 (adler32-zlib) [ 102.937706] Lustre: Lustre: Build Version: 2.17.57_3_g928f38d [ 103.679508] LNet: Added LNI 192.168.206.104@tcp [8/256/0/180] [ 105.447160] Key type lgssc registered [ 107.162656] Lustre: Echo OBD driver; http://www.lustre.org/ [ 120.276709] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 156.093649] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 166.483289] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 166.498874] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 167.668219] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 167.691785] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 167.753907] Lustre: lustre-MDT0000: new disk, initializing [ 167.824357] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 167.843524] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 171.417648] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 183.234211] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 183.340735] Lustre: 6510: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 [ 183.378426] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 183.383715] Lustre: Skipped 1 previous similar message [ 183.464065] Lustre: lustre-MDT0001: new disk, initializing [ 183.518076] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 183.551022] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 183.561283] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 187.472560] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 191.964632] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 200.035750] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 200.217152] Lustre: lustre-OST0000: new disk, initializing [ 200.221546] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 200.227823] Lustre: 8446:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 200.285122] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 205.336816] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 207.903487] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 207.912850] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 208.001750] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 217.721807] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 217.845862] Lustre: lustre-OST0001: new disk, initializing [ 217.848670] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 217.853172] Lustre: 9519:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 217.912972] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 224.135671] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 226.331177] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 226.338410] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 226.389632] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 234.785276] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 242.840160] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 248.721354] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing check_logdir /tmp/testlogs/ [ 253.710440] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing yml_node [ 257.150821] Lustre: DEBUG MARKER: Client: 2.17.57.3 [ 259.719623] Lustre: DEBUG MARKER: MDS: 2.17.57.3 [ 261.936968] Lustre: DEBUG MARKER: OSS: 2.17.57.3 [ 263.501722] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Sat Aug 15 17:15:39 EDT 2026 [ 278.428601] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 286.772469] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 296.428086] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 296.438221] 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 [ 296.454894] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 297.952152] 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 [ 297.952242] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 297.961908] Lustre: Skipped 1 previous similar message [ 297.966089] Lustre: Skipped 1 previous similar message [ 301.198821] Lustre: server umount lustre-MDT0000 complete [ 308.208427] LustreError: 6521:0:(ldlm_lib.c:1192: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. [ 308.226147] LustreError: 6521:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 308.620958] LustreError: 6502:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786828586 with bad export cookie 11982784516665347966 [ 308.624626] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 308.631947] LustreError: 6502:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 308.903434] Lustre: server umount lustre-MDT0001 complete [ 326.009247] Lustre: server umount lustre-OST0000 complete [ 329.680168] Lustre: 3645:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786828591/real 1786828591] req@ffff8bb4037cf800 x1873625356532480/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786828607 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 329.705634] 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 [ 329.721231] Lustre: Skipped 1 previous similar message [ 333.749709] Lustre: server umount lustre-OST0001 complete [ 348.002409] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing unload_modules_local [ 350.859264] Key type lgssc unregistered [ 351.256976] LNet: 14791:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 351.267077] LNetError: 14791:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 351.278842] LNet: Removed LNI 192.168.206.104@tcp [ 352.357155] Key type .llcrypt unregistered [ 352.359163] Key type ._llcrypt unregistered [ 376.386279] Key type ._llcrypt registered [ 376.388763] Key type .llcrypt registered [ 376.475428] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_hostid [ 388.179623] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 388.706128] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 388.829310] alg: No test for adler32 (adler32-zlib) [ 389.903893] Lustre: Lustre: Build Version: 2.17.57_3_g928f38d [ 390.172724] LNet: Added LNI 192.168.206.104@tcp [8/256/0/180] [ 391.871284] Key type lgssc registered [ 393.076744] Lustre: Echo OBD driver; http://www.lustre.org/ [ 444.361511] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 456.114603] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 456.146566] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 457.414334] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 457.447090] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 457.533653] Lustre: lustre-MDT0000: new disk, initializing [ 457.599071] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 457.614507] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 461.685403] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 473.070720] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 473.162655] Lustre: 19224: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 [ 473.183600] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 473.187683] Lustre: Skipped 1 previous similar message [ 473.241350] Lustre: lustre-MDT0001: new disk, initializing [ 473.285438] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 473.299920] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 473.313077] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 477.500553] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 481.625299] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 490.300306] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 490.520402] Lustre: lustre-OST0000: new disk, initializing [ 490.524654] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 490.533044] Lustre: 21161:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 490.586430] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 496.809589] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 497.707511] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 497.721765] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 497.863669] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 509.141706] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 509.319793] Lustre: lustre-OST0001: new disk, initializing [ 509.323780] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 509.329355] Lustre: 22184:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 509.398773] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 514.599317] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 514.611948] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 514.647272] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 514.866870] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 526.039273] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 534.854482] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 542.230947] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 17:20:18 (1786828818) === [ 544.727286] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 17:20:21 (1786828821) [ 544.949697] Lustre: 19232:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 544.967476] Lustre: 19232:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 544.974264] Lustre: 19232:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 544.979545] Lustre: 19232:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 544.987118] Lustre: 19232:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 544.995859] Lustre: 19232:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 545.469873] Lustre: 19232:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 545.475233] Lustre: 19232:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 11 previous similar messages [ 545.483842] Lustre: 19232:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 545.490246] Lustre: 19232:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 545.500253] Lustre: 19232:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 545.511262] Lustre: 19232:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 545.525190] Lustre: 19232:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 545.535778] Lustre: 19232:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 545.541884] Lustre: 19232:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 545.547859] Lustre: 19232:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 545.553851] Lustre: 19232:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 545.559127] Lustre: 19232:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 546.490652] Lustre: 19233:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 546.499423] Lustre: 19233:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 53 previous similar messages [ 546.507489] Lustre: 19233:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 546.515484] Lustre: 19233:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 546.527958] Lustre: 19233:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 546.543431] Lustre: 19233:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 546.552760] Lustre: 19233:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 546.563443] Lustre: 19233:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 546.577039] Lustre: 19233:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 546.589624] Lustre: 19233:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 546.600687] Lustre: 19233:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 546.607092] Lustre: 19233:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 548.553933] Lustre: 21803:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 548.566523] Lustre: 21803:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 116 previous similar messages [ 548.572240] Lustre: 21803:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 548.576646] Lustre: 21803:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 548.584594] Lustre: 21803:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 548.590221] Lustre: 21803:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 548.596520] Lustre: 21803:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 548.601617] Lustre: 21803:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 548.606413] Lustre: 21803:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 548.610386] Lustre: 21803:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 548.618190] Lustre: 21803:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 548.628912] Lustre: 21803:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 551.670486] Lustre: *** cfs_fail_loc=1600, val=3*** [ 555.105542] Lustre: 23370:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 555.105729] Lustre: 21152:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 555.115088] Lustre: 23370:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 96 previous similar messages [ 555.115114] Lustre: 23370:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 555.115118] Lustre: 23370:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 95 previous similar messages [ 555.115126] Lustre: 23370:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 555.115129] Lustre: 23370:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 95 previous similar messages [ 555.115134] Lustre: 23370:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 555.115136] Lustre: 23370:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 95 previous similar messages [ 555.115142] Lustre: 23370:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 555.115145] Lustre: 23370:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 95 previous similar messages [ 555.191777] Lustre: 21152:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 99 previous similar messages [ 555.546348] Lustre: *** cfs_fail_loc=1600, val=3*** [ 568.360810] Lustre: server umount lustre-MDT0000 complete [ 570.848503] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 570.855780] 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 [ 570.875818] Lustre: Skipped 1 previous similar message [ 571.535453] LustreError: 19218:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786828849 with bad export cookie 14769299282294745737 [ 571.538514] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 571.543371] LustreError: 19218:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 571.836647] Lustre: server umount lustre-MDT0001 complete [ 584.356569] Lustre: server umount lustre-OST0000 complete [ 598.811710] Lustre: server umount lustre-OST0001 complete [ 609.104902] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 17:21:24 (1786828884) [ 623.397373] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 634.478630] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 634.776557] LustreError: 26239:0:(ldlm_lib.c:1192: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. [ 634.789602] LustreError: 26239:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 5 previous similar messages [ 634.826619] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 638.775626] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 639.967658] LustreError: 26240:0:(ldlm_lib.c:1192: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. [ 644.064905] LustreError: 26239:0:(ldlm_lib.c:1192: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. [ 646.423857] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 646.729962] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 650.113526] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 652.980060] Lustre: 27381:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 658.573494] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 659.874295] LustreError: 27736:0:(ldlm_lib.c:1192: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. [ 659.888961] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 664.443780] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 665.063601] LustreError: 27736:0:(ldlm_lib.c:1192: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. [ 672.848475] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 673.020799] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 673.028799] Lustre: Skipped 1 previous similar message [ 678.374776] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:40 to 0x2c0000401:65) [ 678.820364] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 686.383858] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 690.137675] Lustre: 29253:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 691.640488] Lustre: 26236:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 691.648888] Lustre: 26236:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 66 previous similar messages [ 691.654758] Lustre: 26236:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 691.659629] Lustre: 26236:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 63 previous similar messages [ 691.671415] Lustre: 26236:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 691.683000] Lustre: 26236:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 691.689074] Lustre: 26236:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 691.694802] Lustre: 26236:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 691.700622] Lustre: 26236:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 691.706120] Lustre: 26236:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 691.711974] Lustre: 26236:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 691.720058] Lustre: 26236:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 67 previous similar messages [ 697.282986] Lustre: *** cfs_fail_loc=1501, val=0*** [ 705.742143] Lustre: Failing over lustre-MDT0000 [ 706.019711] Lustre: server umount lustre-MDT0000 complete [ 708.063637] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 708.070064] 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 [ 708.079075] LustreError: 26240:0:(ldlm_lib.c:1192: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. [ 708.095367] LustreError: 26240:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 3 previous similar messages [ 709.090886] 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 [ 709.122724] Lustre: Skipped 2 previous similar messages [ 717.598135] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 717.755325] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 717.869844] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 717.899871] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 721.592694] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 722.912196] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 722.915656] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 722.954692] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 722.977355] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 722.979874] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 725.244868] Lustre: *** cfs_fail_loc=1505, val=0*** [ 732.841045] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 17:23:29 (1786829009) [ 734.571301] Lustre: 28561:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 734.578885] Lustre: 28561:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 322 previous similar messages [ 734.584834] Lustre: 28561:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 734.593825] Lustre: 28561:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 734.605865] Lustre: 28561:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 734.619138] Lustre: 28561:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 734.625916] Lustre: 28561:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 734.631506] Lustre: 28561:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 734.641149] Lustre: 28561:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 734.648678] Lustre: 28561:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 734.657480] Lustre: 28561:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 734.665287] Lustre: 28561:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 739.541692] Lustre: *** cfs_fail_loc=1502, val=0*** [ 748.038167] Lustre: Failing over lustre-MDT0000 [ 748.200140] Lustre: server umount lustre-MDT0000 complete [ 748.512122] 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 [ 748.512468] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 748.512745] LustreError: 26235:0:(ldlm_lib.c:1192: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. [ 748.512753] LustreError: 26235:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 748.521882] Lustre: Skipped 3 previous similar messages [ 758.838380] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 759.058113] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 759.383517] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 764.016720] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 764.388421] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 764.390272] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 764.403195] Lustre: Skipped 3 previous similar messages [ 764.419852] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 764.508345] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 764.510151] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 767.685329] Lustre: *** cfs_fail_loc=1505, val=0*** [ 775.526656] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 17:24:11 (1786829051) [ 777.010376] Lustre: 26235:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 777.021758] Lustre: 26235:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 322 previous similar messages [ 777.025215] Lustre: 26235:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 777.032018] Lustre: 26235:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 321 previous similar messages [ 777.042539] Lustre: 26235:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 777.052294] Lustre: 26235:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 777.059533] Lustre: 26235:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 777.065412] Lustre: 26235:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 777.072480] Lustre: 26235:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 777.079625] Lustre: 26235:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 321 previous similar messages [ 777.086397] Lustre: 26235:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 777.091610] Lustre: 26235:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 321 previous similar messages [ 781.551187] Lustre: *** cfs_fail_loc=1504, val=0*** [ 781.557974] Lustre: *** cfs_fail_loc=1504, val=0*** [ 781.566685] Lustre: Skipped 1 previous similar message [ 788.815570] Lustre: Failing over lustre-MDT0000 [ 789.025567] Lustre: server umount lustre-MDT0000 complete [ 789.984721] 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 [ 790.008517] LustreError: 26240:0:(ldlm_lib.c:1192: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. [ 790.036927] LustreError: 26240:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 14 previous similar messages [ 799.133139] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 799.293236] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 799.549410] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 799.554275] Lustre: Skipped 1 previous similar message [ 799.593770] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 803.924828] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 804.847673] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 804.848303] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 804.857429] Lustre: Skipped 3 previous similar messages [ 804.892707] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 804.944172] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 804.945943] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 806.732092] Lustre: *** cfs_fail_loc=1505, val=0*** [ 813.962954] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 17:24:49 (1786829089) [ 820.578650] Lustre: *** cfs_fail_loc=1603, val=0*** [ 827.797683] Lustre: Failing over lustre-MDT0000 [ 828.082650] Lustre: server umount lustre-MDT0000 complete [ 830.436575] 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 [ 830.437917] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 830.451044] Lustre: Skipped 4 previous similar messages [ 836.925766] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 837.022135] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 837.290538] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 841.542226] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 842.725222] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 842.732325] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 842.737495] Lustre: Skipped 3 previous similar messages [ 842.758506] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 842.783572] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 842.783702] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 850.751617] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 17:25:27 (1786829127) [ 852.247241] Lustre: 28564:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 852.258105] Lustre: 28564:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 644 previous similar messages [ 852.262158] Lustre: 28564:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 852.267274] Lustre: 28564:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 852.274915] Lustre: 28564:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 852.282376] Lustre: 28564:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 852.289588] Lustre: 28564:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 852.296539] Lustre: 28564:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 852.303031] Lustre: 28564:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 852.307387] Lustre: 28564:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 852.311064] Lustre: 28564:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 852.317537] Lustre: 28564:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 644 previous similar messages [ 857.547912] Lustre: *** cfs_fail_loc=1604, val=0*** [ 865.351515] Lustre: Failing over lustre-MDT0000 [ 865.596421] Lustre: server umount lustre-MDT0000 complete [ 868.321538] 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 [ 868.325093] LustreError: 26239:0:(ldlm_lib.c:1192: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. [ 868.334781] Lustre: Skipped 4 previous similar messages [ 868.359949] LustreError: 26239:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 15 previous similar messages [ 874.662228] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 874.798625] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 875.068537] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 879.039720] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 880.102341] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 880.109389] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 880.127733] Lustre: Skipped 3 previous similar messages [ 880.150368] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 880.193211] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 880.194597] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 888.477465] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 17:26:04 (1786829164) [ 895.624915] Lustre: *** cfs_fail_loc=1605, val=0*** [ 902.764123] Lustre: Failing over lustre-MDT0000 [ 903.061668] Lustre: server umount lustre-MDT0000 complete [ 905.701265] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 905.707678] 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 [ 905.745723] Lustre: Skipped 3 previous similar messages [ 913.218241] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 913.290727] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 913.565849] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 917.744738] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 919.014209] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 919.023094] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 919.031552] Lustre: Skipped 3 previous similar messages [ 919.045716] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 919.075606] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 919.075994] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 926.530085] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 17:26:42 (1786829202) [ 932.362404] Lustre: *** cfs_fail_loc=161d, val=0*** [ 938.788285] Lustre: Failing over lustre-MDT0000 [ 938.971037] Lustre: server umount lustre-MDT0000 complete [ 939.487506] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 948.302803] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 948.447188] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 948.713447] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 948.718198] Lustre: Skipped 3 previous similar messages [ 948.747720] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 952.929633] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 953.826989] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 953.838269] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 953.852022] Lustre: Skipped 3 previous similar messages [ 953.872566] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 953.923498] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 953.928738] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 961.729542] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 17:27:17 (1786829237) [ 964.267347] Lustre: *** cfs_fail_loc=1603, val=0*** [ 975.085865] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 17:27:31 (1786829251) [ 981.039071] Lustre: *** cfs_fail_loc=1603, val=0*** [ 981.044655] Lustre: 28561:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 279, rollback = 2 [ 981.059459] Lustre: 28561:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1288 previous similar messages [ 981.073649] Lustre: 28561:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 981.090313] Lustre: 28561:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1288 previous similar messages [ 981.098035] Lustre: 28561:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 2/2/0, xattr_set: 4/279/0 [ 981.104012] Lustre: 28561:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 981.111384] Lustre: 28561:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 981.116711] Lustre: 28561:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 981.122658] Lustre: 28561:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/16/0, delete: 0/0/0 [ 981.126899] Lustre: 28561:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 981.133667] Lustre: 28561:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 981.139408] Lustre: 28561:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1289 previous similar messages [ 982.119359] Lustre: *** cfs_fail_loc=1604, val=0*** [ 992.055877] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 17:27:48 (1786829268) [ 1026.649110] Lustre: Failing over lustre-MDT0000 [ 1027.101264] Lustre: server umount lustre-MDT0000 complete [ 1030.626806] 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 [ 1030.634602] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1030.639519] LustreError: 28561:0:(ldlm_lib.c:1192: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. [ 1030.639530] LustreError: 28561:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 20 previous similar messages [ 1030.647875] Lustre: Skipped 6 previous similar messages [ 1031.943603] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1042.591543] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1047.014686] Lustre: 16386:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786829308/real 1786829308] req@ffff8bb535ed9880 x1873625658094208/t0(0) o400->MGC192.168.206.104@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786829324 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1047.060458] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1054.585409] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1054.623226] Lustre: lustre-MDT0000: reset Object Index mappings [ 1057.252710] LustreError: 16384:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8bb537534380 x1873625658103552/t0(0) o250->MGC192.168.206.104@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 [ 1057.648304] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1061.745445] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1062.882215] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1062.905332] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1062.913550] Lustre: Skipped 3 previous similar messages [ 1062.931233] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1062.967706] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 1062.972368] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 1065.336682] LustreError: 42892:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1065.368089] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1067.423246] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1067.436722] Lustre: Skipped 1 previous similar message [ 1074.506178] Lustre: Failing over lustre-MDT0000 [ 1074.728369] Lustre: server umount lustre-MDT0000 complete [ 1078.240644] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1084.141245] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1088.291856] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1089.544262] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 1089.547820] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 1091.287553] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1098.511198] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 17:29:34 (1786829374) [ 1100.893306] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1109.270215] Lustre: Failing over lustre-MDT0000 [ 1111.435734] Lustre: server umount lustre-MDT0000 complete [ 1116.138992] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1124.688813] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1131.488102] Lustre: 16386:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786829393/real 1786829393] req@ffff8bb408ffd180 x1873625658187520/t0(0) o400->MGC192.168.206.104@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1786829409 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1136.413745] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1136.440827] Lustre: lustre-MDT0000: reset Object Index mappings [ 1141.731514] LustreError: 16384:0:(client.c:1391:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff8bb5081e7800 x1873625658196608/t0(0) o250->MGC192.168.206.104@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 [ 1142.072078] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1142.084254] Lustre: Skipped 1 previous similar message [ 1146.727253] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1147.362941] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1147.365917] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1147.378299] Lustre: Skipped 1 previous similar message [ 1147.398313] Lustre: Skipped 7 previous similar messages [ 1147.428454] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1147.435507] Lustre: Skipped 1 previous similar message [ 1147.485584] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 1147.485674] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1150.162233] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1150.170707] Lustre: Skipped 2 previous similar messages [ 1163.529394] Lustre: Failing over lustre-MDT0000 [ 1163.760358] Lustre: server umount lustre-MDT0000 complete [ 1167.840621] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1167.843628] 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 [ 1167.847852] LustreError: Skipped 1 previous similar message [ 1167.864501] Lustre: Skipped 12 previous similar messages [ 1172.117789] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1176.593933] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1177.622522] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 1177.622898] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1180.040029] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1180.044373] Lustre: Skipped 84 previous similar messages [ 1187.570485] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 17:31:03 (1786829463) [ 1194.606646] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1194.613321] Lustre: Skipped 7 previous similar messages [ 1213.914792] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 17:31:30 (1786829490) [ 1222.383734] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1222.385903] Lustre: Skipped 8 previous similar messages [ 1245.578958] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 17:32:01 (1786829521) [ 1247.350873] Lustre: 26236:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 1247.356567] Lustre: 26236:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1398 previous similar messages [ 1247.362652] Lustre: 26236:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1247.368910] Lustre: 26236:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1398 previous similar messages [ 1247.375150] Lustre: 26236:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1247.383413] Lustre: 26236:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1398 previous similar messages [ 1247.387103] Lustre: 26236:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1247.391704] Lustre: 26236:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1399 previous similar messages [ 1247.396213] Lustre: 26236:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 1247.401090] Lustre: 26236:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1399 previous similar messages [ 1247.406473] Lustre: 26236:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1247.411854] Lustre: 26236:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1399 previous similar messages [ 1256.821846] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1256.827763] Lustre: Skipped 12 previous similar messages [ 1262.672146] Lustre: Failing over lustre-MDT0000 [ 1263.121787] Lustre: server umount lustre-MDT0000 complete [ 1272.097084] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1272.216768] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1272.226590] LustreError: Skipped 3 previous similar messages [ 1272.412858] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1272.416615] Lustre: Skipped 4 previous similar messages [ 1272.438701] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1272.449502] Lustre: Skipped 1 previous similar message [ 1277.014605] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1277.412090] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 1277.413903] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1277.419830] Lustre: Skipped 7 previous similar messages [ 1277.443718] Lustre: Skipped 1 previous similar message [ 1277.456021] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1277.460758] Lustre: Skipped 1 previous similar message [ 1277.497276] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:854 to 0x2c0000401:897) [ 1277.498072] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:853 to 0x280000401:897) [ 1285.173730] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 17:32:41 (1786829561) [ 1296.823050] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 1313.214928] Lustre: 53002:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1336.587745] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1340.020639] Lustre: 54138:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1346.592499] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1346.596855] Lustre: Skipped 81 previous similar messages [ 1348.921283] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1349.983392] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1351.007324] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1353.056937] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1353.060172] Lustre: Skipped 1 previous similar message [ 1353.183410] Lustre: Failing over lustre-MDT0000 [ 1353.473492] Lustre: server umount lustre-MDT0000 complete [ 1354.214386] LustreError: 26235:0:(ldlm_lib.c:1192: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. [ 1354.238277] LustreError: 26235:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 80 previous similar messages [ 1354.241979] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1354.262318] LustreError: Skipped 1 previous similar message [ 1363.148487] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1368.068564] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1369.165445] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 1369.168144] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:946 to 0x2c0000401:961) [ 1376.407697] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 17:34:13 (1786829653) [ 1379.299233] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1379.306992] Lustre: Skipped 2 previous similar messages [ 1384.422921] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1384.440917] Lustre: Skipped 3 previous similar messages [ 1384.798412] Lustre: server umount lustre-MDT0000 complete [ 1388.451906] LustreError: 26983:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786829666 with bad export cookie 14769299282294959076 [ 1388.463483] LustreError: 26983:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1388.776618] Lustre: server umount lustre-MDT0001 complete [ 1403.012240] Lustre: server umount lustre-OST0000 complete [ 1405.665074] Lustre: 16386:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786829667/real 1786829667] req@ffff8bb5354c5f80 x1873625658509952/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786829683 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1406.511745] Lustre: server umount lustre-OST0001 complete [ 1412.420565] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_hostid [ 1419.384339] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 1464.641079] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 1474.581341] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1475.021189] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1475.096441] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1475.256243] Lustre: lustre-MDT0000: new disk, initializing [ 1475.516950] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1480.136061] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1490.600071] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1490.780309] Lustre: 59195: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 [ 1490.863432] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1490.866969] Lustre: Skipped 1 previous similar message [ 1490.915156] Lustre: lustre-MDT0001: new disk, initializing [ 1491.019753] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1491.048037] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1495.054904] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1499.417681] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1505.956559] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1506.140284] Lustre: lustre-OST0000: new disk, initializing [ 1506.143600] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1506.149632] Lustre: 60832:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1507.677620] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1507.698646] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1507.728230] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1511.305937] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1520.973137] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1521.102481] Lustre: lustre-OST0001: new disk, initializing [ 1521.108238] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1521.113858] Lustre: 61700:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 1522.314450] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1522.332116] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1522.427555] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1528.282314] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1537.238353] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1540.199178] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1550.216395] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1550.972648] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1550.977655] Lustre: Skipped 19 previous similar messages [ 1555.545654] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1555.551886] Lustre: Skipped 5 previous similar messages [ 1571.457567] Lustre: Failing over lustre-MDT0000 [ 1571.775317] Lustre: server umount lustre-MDT0000 complete [ 1572.832725] 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 [ 1572.843087] Lustre: Skipped 13 previous similar messages [ 1579.937360] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1580.000860] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1580.012433] LustreError: Skipped 2 previous similar messages [ 1580.251866] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1580.261508] Lustre: Skipped 1 previous similar message [ 1584.279856] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1585.640313] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1585.641715] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1585.647610] Lustre: Skipped 7 previous similar messages [ 1585.654359] Lustre: Skipped 1 previous similar message [ 1585.677419] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1585.690604] Lustre: Skipped 1 previous similar message [ 1585.735786] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1585.747634] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 1585.751816] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1591.265453] Lustre: Failing over lustre-MDT0000 [ 1591.545023] Lustre: server umount lustre-MDT0000 complete [ 1599.353588] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1603.622724] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1605.161506] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1605.172036] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 1605.180535] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1608.451696] Lustre: Failing over lustre-MDT0000 [ 1608.661873] Lustre: server umount lustre-MDT0000 complete [ 1615.798152] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1619.761481] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1621.523263] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1621.523289] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:129) [ 1624.520539] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1632.738811] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 17:38:29 (1786829909) [ 1643.665322] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 1659.982183] Lustre: 68596:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1680.838346] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1684.854606] Lustre: 69735:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1759.357579] Lustre: 59203:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 1759.364652] Lustre: 59203:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 15944 previous similar messages [ 1759.370991] Lustre: 59203:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1759.377905] Lustre: 59203:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 15943 previous similar messages [ 1759.382783] Lustre: 59203:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1759.387707] Lustre: 59203:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 15944 previous similar messages [ 1759.392608] Lustre: 59203:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 1759.399270] Lustre: 59203:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 15944 previous similar messages [ 1759.404336] Lustre: 59203:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 1759.409324] Lustre: 59203:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 15944 previous similar messages [ 1759.414287] Lustre: 59203:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 1759.418765] Lustre: 59203:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 15944 previous similar messages [ 1801.735356] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 17:41:17 (1786830077) [ 1849.062185] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1849.067255] Lustre: Skipped 4 previous similar messages [ 1871.611231] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1871.613721] Lustre: Skipped 7 previous similar messages [ 1905.795560] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 17:43:02 (1786830182) [ 1949.773536] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1957.784866] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1957.790298] Lustre: Skipped 468 previous similar messages [ 1973.784652] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1973.789699] Lustre: Skipped 922 previous similar messages [ 2005.792105] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2005.795763] Lustre: Skipped 1750 previous similar messages [ 2014.375320] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2014.382910] Lustre: Skipped 2599 previous similar messages [ 2246.165619] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 17:48:42 (1786830522) [ 2386.281451] Lustre: 69026:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 2386.297208] Lustre: 69026:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 22942 previous similar messages [ 2386.303990] Lustre: 69026:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2386.312594] Lustre: 69026:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 22942 previous similar messages [ 2386.319624] Lustre: 69026:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2386.327635] Lustre: 69026:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 22942 previous similar messages [ 2386.334807] Lustre: 69026:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2386.341819] Lustre: 69026:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 22942 previous similar messages [ 2386.347761] Lustre: 69026:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 2386.356600] Lustre: 69026:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 22942 previous similar messages [ 2386.364550] Lustre: 69026:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2386.370656] Lustre: 69026:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 22942 previous similar messages [ 2393.495764] Lustre: server umount lustre-MDT0000 complete [ 2394.595093] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2394.597885] 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 [ 2394.606732] LustreError: Skipped 4 previous similar messages [ 2394.609901] LustreError: 59203:0:(ldlm_lib.c:1192: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. [ 2394.609914] LustreError: 59203:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 26 previous similar messages [ 2394.617309] Lustre: Skipped 13 previous similar messages [ 2396.463510] LustreError: 68598:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786830674 with bad export cookie 14769299282294978179 [ 2396.470452] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2396.477083] LustreError: Skipped 2 previous similar messages [ 2396.708670] Lustre: server umount lustre-MDT0001 complete [ 2410.107131] Lustre: server umount lustre-OST0000 complete [ 2423.950992] Lustre: server umount lustre-OST0001 complete [ 2429.730960] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2436.813309] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2452.319411] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2457.439310] LustreError: 75292:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.104@tcp: failed processing log, type 4: rc = -110 [ 2483.167198] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2483.177669] Lustre: Skipped 8 previous similar messages [ 2489.708868] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2493.027117] Lustre: 75877:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2493.057185] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2496.104208] Lustre: 75877:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2504.320888] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 17:53:00 (1786830780) [ 2517.040759] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 2526.455732] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2526.848118] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3272 to 0x280000401:3297) [ 2530.508957] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2538.588058] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2542.565785] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2545.348308] Lustre: 78541:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2560.035482] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2560.316330] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2560.325670] Lustre: Skipped 2 previous similar messages [ 2565.635896] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3207 to 0x2c0000401:3233) [ 2567.247580] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2574.335868] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2577.842305] Lustre: 80037:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2581.715468] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2582.217187] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2582.225874] Lustre: Skipped 5 previous similar messages [ 2587.506531] Lustre: Failing over lustre-OST0000 [ 2587.688275] Lustre: server umount lustre-OST0000 complete [ 2588.129794] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2596.773659] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2596.951480] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2596.959799] Lustre: Skipped 2 previous similar messages [ 2598.571404] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2598.584510] Lustre: Skipped 2 previous similar messages [ 2598.634815] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2598.638600] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2598.642602] Lustre: *** cfs_fail_loc=215, val=0*** [ 2598.646656] Lustre: Skipped 2 previous similar messages [ 2598.669396] Lustre: Skipped 11 previous similar messages [ 2603.999902] Lustre: *** cfs_fail_loc=215, val=0*** [ 2604.008023] Lustre: Skipped 4 previous similar messages [ 2604.077387] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2607.541406] Lustre: 81438:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2607.565306] Lustre: 81438:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2609.124275] Lustre: *** cfs_fail_loc=215, val=0*** [ 2609.131644] Lustre: Skipped 1 previous similar message [ 2610.187220] Lustre: Failing over lustre-OST0000 [ 2610.341248] Lustre: server umount lustre-OST0000 complete [ 2618.800151] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2620.398863] Lustre: *** cfs_fail_loc=215, val=0*** [ 2625.503772] Lustre: *** cfs_fail_loc=215, val=0*** [ 2625.509542] Lustre: Skipped 2 previous similar messages [ 2625.531941] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2631.137784] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2634.723098] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2634.733432] Lustre: Skipped 3 previous similar messages [ 2637.715625] Lustre: server umount lustre-MDT0000 complete [ 2643.067096] LustreError: 75300:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786830921 with bad export cookie 14769299282296536449 [ 2643.080683] LustreError: 75300:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2643.790454] Lustre: server umount lustre-MDT0001 complete [ 2660.051214] Lustre: server umount lustre-OST0000 complete [ 2660.329943] Lustre: 16386:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786830922/real 1786830922] req@ffff8bb535d91c00 x1873625662383232/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786830938 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 2664.836086] Lustre: server umount lustre-OST0001 complete [ 2673.654225] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 17:55:49 (1786830949) [ 2687.648906] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 2697.131495] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2697.541519] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2697.545079] Lustre: Skipped 2 previous similar messages [ 2701.806807] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2710.342346] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2715.538449] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2718.644918] Lustre: 85822:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2724.364464] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2729.685668] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2737.343675] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2742.643019] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3207 to 0x2c0000401:3265) [ 2742.656711] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 2742.959056] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2751.034256] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2754.702300] Lustre: 87693:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2787.120361] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 17:57:43 (1786831063) [ 2800.470879] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 17:57:56 (1786831076) [ 2801.653881] Lustre: *** cfs_fail_loc=160f, val=0*** [ 2812.678983] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 17:58:08 (1786831088) [ 2816.109642] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2816.111460] Lustre: Skipped 1 previous similar message [ 2864.095725] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2864.105377] LustreError: Skipped 2 previous similar messages [ 2864.120102] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2868.788302] Lustre: server umount lustre-MDT0000 complete [ 2872.128181] LustreError: 84661:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786831150 with bad export cookie 14769299282296544947 [ 2872.136784] LustreError: 84661:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2872.399032] Lustre: server umount lustre-MDT0001 complete [ 2886.649299] Lustre: server umount lustre-OST0000 complete [ 2900.615538] Lustre: server umount lustre-OST0001 complete [ 2914.656895] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 2923.547581] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2927.889162] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2935.800175] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2939.766898] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2941.976955] Lustre: 93555:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2946.806832] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2948.078461] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 2951.851649] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2958.889869] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2959.032127] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2959.036645] Lustre: Skipped 6 previous similar messages [ 2961.064602] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 2961.075399] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 2961.078412] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 2964.350372] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2970.272772] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2973.086118] Lustre: 95423:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2978.099492] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 18:00:54 (1786831254) [ 2982.743372] Lustre: *** cfs_fail_loc=1610, val=0*** [ 2982.744928] Lustre: Skipped 63 previous similar messages [ 2988.238729] Lustre: 94356:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 2988.247926] Lustre: 94356:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1555 previous similar messages [ 2988.255655] Lustre: 94356:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 2988.265402] Lustre: 94356:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1555 previous similar messages [ 2988.271885] Lustre: 94356:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2988.277615] Lustre: 94356:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1555 previous similar messages [ 2988.283176] Lustre: 94356:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 2988.289458] Lustre: 94356:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1555 previous similar messages [ 2988.294703] Lustre: 94356:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 2988.301406] Lustre: 94356:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1555 previous similar messages [ 2988.309584] Lustre: 94356:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2988.322642] Lustre: 94356:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1555 previous similar messages [ 3002.337893] 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 [ 3002.340681] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3002.355681] Lustre: Skipped 15 previous similar messages [ 3002.358611] Lustre: Skipped 5 previous similar messages [ 3007.457408] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3007.468401] Lustre: Skipped 5 previous similar messages [ 3015.135112] Lustre: lustre-MDT0000 is waiting for obd_unlinked_exports more than 8 seconds. The obd refcount = 3. Is it stuck? [ 3015.266960] Lustre: server umount lustre-MDT0000 complete [ 3017.700953] LustreError: 96126:0:(ldlm_lib.c:1192: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. [ 3017.712041] LustreError: 96126:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 50 previous similar messages [ 3017.898770] LustreError: 95425:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786831295 with bad export cookie 14769299282296573367 [ 3017.904343] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3017.911394] LustreError: 95425:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3017.923779] LustreError: Skipped 2 previous similar messages [ 3018.136501] Lustre: server umount lustre-MDT0001 complete [ 3031.086098] Lustre: server umount lustre-OST0000 complete [ 3044.831653] Lustre: server umount lustre-OST0001 complete [ 3060.669525] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 3069.207205] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3072.938528] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3079.515141] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3084.036976] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3086.355388] Lustre: 99476:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3091.446599] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3094.767820] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3096.132633] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3101.887277] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3104.102595] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3104.107341] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3104.166163] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3106.735759] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3112.619438] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3121.915287] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 18:03:18 (1786831398) [ 3125.564149] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3125.568067] Lustre: Skipped 63 previous similar messages [ 3125.800644] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3135.384419] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 18:03:31 (1786831411) [ 3137.682272] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3137.739561] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3137.742184] Lustre: Skipped 2 previous similar messages [ 3147.476950] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 18:03:43 (1786831423) [ 3149.181041] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3150.806945] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 18:03:47 (1786831427) [ 3156.487383] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3156.575076] LustreError: 98347:0:(osp_object.c:618:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200003ab2:0x1:0x0]: rc = -5 [ 3156.585537] LustreError: 98347:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0001: migrate [0x240002340:0x6c:0x0]/s47 failed: rc = -5 [ 3163.955749] LustreError: 101461:0:(lod_object.c:945:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x4d:0x0]:1 for the striped directory [0x240002340:0x83:0x0] is out of the known LMV EA range [0 - 0], failout [ 3167.503246] LustreError: 98334:0:(lod_object.c:945:lod_load_lmv_shards()) lustre-MDT0001-mdtlov: the shard [0x200003ab1:0x4d:0x0]:1 for the striped directory [0x240002340:0x83:0x0] is out of the known LMV EA range [0 - 0], failout [ 3167.515355] LustreError: 98334:0:(mdt_handler.c:1498:mdt_getattr_internal()) lustre-MDT0001: getattr error for [0x240002340:0x83:0x0]: rc = -5 [ 3206.630508] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3206.634538] Lustre: Skipped 4 previous similar messages [ 3209.046892] Lustre: server umount lustre-MDT0000 complete [ 3215.782653] LustreError: 102547:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786831493 with bad export cookie 14769299282296588102 [ 3215.792598] LustreError: 102547:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 3215.982856] Lustre: server umount lustre-MDT0001 complete [ 3232.864765] Lustre: 16387:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786831494/real 1786831494] req@ffff8bb4061a1180 x1873625662991488/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786831510 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3233.066355] Lustre: server umount lustre-OST0000 complete [ 3236.064660] Lustre: 16385:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786831498/real 1786831498] req@ffff8bb409a1ea00 x1873625662991744/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786831514 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3240.420721] Lustre: server umount lustre-OST0001 complete [ 3255.329484] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing unload_modules_local [ 3258.067346] Key type lgssc unregistered [ 3258.388815] LNet: 105176:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3258.397222] LNetError: 105176:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3259.435309] LNet: Removed LNI 192.168.206.104@tcp [ 3260.250164] Key type .llcrypt unregistered [ 3260.251739] Key type ._llcrypt unregistered [ 3280.251977] Key type ._llcrypt registered [ 3280.253740] Key type .llcrypt registered [ 3280.371650] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_hostid [ 3290.653754] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 3291.547669] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3291.580163] alg: No test for adler32 (adler32-zlib) [ 3292.593106] Lustre: Lustre: Build Version: 2.17.57_3_g928f38d [ 3292.793768] LNet: Added LNI 192.168.206.104@tcp [8/256/0/180] [ 3294.455167] Key type lgssc registered [ 3295.372170] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3333.711592] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 3345.596967] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3345.642526] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3346.843440] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3346.869612] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3346.962856] Lustre: lustre-MDT0000: new disk, initializing [ 3347.031220] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3347.049410] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3350.724646] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3361.626017] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3361.702209] Lustre: 109609: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 [ 3361.729365] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3361.734442] Lustre: Skipped 1 previous similar message [ 3361.792739] Lustre: lustre-MDT0001: new disk, initializing [ 3361.836632] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3361.858275] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3361.865616] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3364.862817] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3368.600842] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3375.603985] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3375.847654] Lustre: lustre-OST0000: new disk, initializing [ 3375.852113] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3375.859673] Lustre: 111547:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3375.929171] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3376.947597] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3376.961871] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3377.055477] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3381.519523] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3392.927095] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3393.049951] Lustre: lustre-OST0001: new disk, initializing [ 3393.053122] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3393.057538] Lustre: 112569:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3393.121354] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3398.450129] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3400.699960] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3400.708916] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3400.731199] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3407.675819] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3411.527715] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3416.060655] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 18:08:12 (1786831692) === [ 3420.950407] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 18:08:17 (1786831697) [ 3421.118821] Lustre: 109617:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3421.127374] Lustre: 109617:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3421.134523] Lustre: 109617:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3421.140540] Lustre: 109617:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3421.146296] Lustre: 109617:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3421.154250] Lustre: 109617:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3421.635895] Lustre: 109617:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3421.641463] Lustre: 109617:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 24 previous similar messages [ 3421.645446] Lustre: 109617:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3421.649503] Lustre: 109617:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3421.659915] Lustre: 109617:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3421.669385] Lustre: 109617:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3421.678780] Lustre: 109617:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3421.684578] Lustre: 109617:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3421.691406] Lustre: 109617:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3421.695179] Lustre: 109617:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3421.700491] Lustre: 109617:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3421.705810] Lustre: 109617:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3422.639319] Lustre: 113759:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3422.646699] Lustre: 113759:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 167 previous similar messages [ 3422.650555] Lustre: 113759:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3422.654679] Lustre: 113759:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 167 previous similar messages [ 3422.660988] Lustre: 113759:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3422.668827] Lustre: 113759:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 167 previous similar messages [ 3422.679125] Lustre: 113759:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 3422.686993] Lustre: 113759:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 167 previous similar messages [ 3422.694225] Lustre: 113759:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3422.700547] Lustre: 113759:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 167 previous similar messages [ 3422.706435] Lustre: 113759:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3422.716256] Lustre: 113759:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 167 previous similar messages [ 3424.130122] Lustre: *** cfs_fail_loc=1613, val=0*** [ 3432.152166] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 18:08:28 (1786831708) [ 3433.244257] Lustre: 109617:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 257 < left 278, rollback = 2 [ 3433.248815] Lustre: 109617:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 116 previous similar messages [ 3433.254693] Lustre: 109617:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3433.258948] Lustre: 109617:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3433.263014] Lustre: 109617:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3433.270071] Lustre: 109617:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3433.277741] Lustre: 109617:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3433.282867] Lustre: 109617:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3433.289032] Lustre: 109617:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3433.295792] Lustre: 109617:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3433.300277] Lustre: 109617:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3433.306483] Lustre: 109617:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3434.114949] Lustre: *** cfs_fail_loc=1614, val=0*** [ 3437.268644] Lustre: 111537:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 275, rollback = 2 [ 3437.275074] Lustre: 111537:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 12 previous similar messages [ 3437.281639] Lustre: 111537:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 3437.288497] Lustre: 111537:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 3437.293971] Lustre: 111537:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 3/275/0 [ 3437.303619] Lustre: 111537:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 3437.310835] Lustre: 111537:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 3437.316456] Lustre: 111537:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 3437.324871] Lustre: 111537:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 3437.333420] Lustre: 111537:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 3437.338813] Lustre: 111537:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3437.344403] Lustre: 111537:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 3442.412780] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 18:08:39 (1786831719) [ 3444.353949] Lustre: *** cfs_fail_loc=1615, val=0*** [ 3444.358363] Lustre: Skipped 1 previous similar message [ 3458.509866] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 3460.231372] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 18:08:56 (1786831736) [ 3460.684700] Lustre: 109616:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3460.691706] Lustre: 109616:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 22 previous similar messages [ 3460.698188] Lustre: 109616:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3460.703186] Lustre: 109616:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 3460.710583] Lustre: 109616:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3460.715284] Lustre: 109616:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 3460.719884] Lustre: 109616:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3460.725651] Lustre: 109616:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 3460.730256] Lustre: 109616:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3460.733941] Lustre: 109616:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 3460.738607] Lustre: 109616:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3460.742501] Lustre: 109616:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 3462.643471] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3462.697880] Lustre: *** cfs_fail_loc=1617, val=0*** [ 3464.898086] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3464.903285] Lustre: Skipped 5 previous similar messages [ 3482.666670] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 18:09:19 (1786831759) [ 3483.063527] Lustre: 113759:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3483.077487] Lustre: 113759:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 24 previous similar messages [ 3483.090270] Lustre: 113759:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3483.100579] Lustre: 113759:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3483.109257] Lustre: 113759:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3483.116171] Lustre: 113759:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3483.125219] Lustre: 113759:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3483.135865] Lustre: 113759:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3483.143371] Lustre: 113759:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 3483.157213] Lustre: 113759:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3483.174129] Lustre: 113759:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3483.193513] Lustre: 113759:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 3484.693711] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3484.696091] Lustre: Skipped 5 previous similar messages [ 3518.434757] 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 [ 3518.436196] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3518.448762] Lustre: Skipped 1 previous similar message [ 3523.552039] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3523.559248] Lustre: Skipped 6 previous similar messages [ 3523.928046] Lustre: server umount lustre-MDT0000 complete [ 3527.160288] LustreError: 109600:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786831805 with bad export cookie 16935103863666984201 [ 3527.167635] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3527.176507] LustreError: 109600:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 3527.583305] Lustre: server umount lustre-MDT0001 complete [ 3541.389655] Lustre: server umount lustre-OST0000 complete [ 3554.670903] Lustre: server umount lustre-OST0001 complete [ 3569.313442] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 3579.533033] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3579.917473] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3583.910720] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3584.992266] LustreError: 118282:0:(ldlm_lib.c:1192: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. [ 3585.002261] LustreError: 118282:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 2 previous similar messages [ 3589.089077] LustreError: 118283:0:(ldlm_lib.c:1192: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. [ 3590.878115] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3591.124904] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3595.151374] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3598.270187] Lustre: 119420:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3604.283325] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3604.450100] LustreError: 119774:0:(ldlm_lib.c:1192: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. [ 3610.080463] LustreError: 119776:0:(ldlm_lib.c:1192: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. [ 3610.093119] LustreError: 119776:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 1 previous similar message [ 3610.105625] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 3610.275155] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3615.199918] LustreError: 120119:0:(ldlm_lib.c:1192: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. [ 3616.258067] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 3619.264223] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3619.394167] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3619.397215] Lustre: Skipped 1 previous similar message [ 3624.421834] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 3624.426603] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 3624.915461] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3632.165483] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3635.422736] Lustre: 121292:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3647.196750] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 18:12:03 (1786831923) [ 3647.516676] Lustre: 118278:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3647.525856] Lustre: 118278:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3647.530910] Lustre: 118278:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3647.535512] Lustre: 118278:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3647.542614] Lustre: 118278:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3647.548247] Lustre: 118278:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3647.557665] Lustre: 118278:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3647.563799] Lustre: 118278:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3647.569215] Lustre: 118278:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3647.572983] Lustre: 118278:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3647.577920] Lustre: 118278:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3647.582909] Lustre: 118278:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3649.405225] Lustre: *** cfs_fail_loc=1618, val=0*** [ 3649.407169] Lustre: Skipped 3 previous similar messages [ 3683.296102] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3683.300518] 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 [ 3683.316038] Lustre: Skipped 2 previous similar messages [ 3683.325252] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3685.855593] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3685.856291] 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 [ 3685.865025] Lustre: Skipped 1 previous similar message [ 3685.881776] Lustre: Skipped 1 previous similar message [ 3689.123496] Lustre: server umount lustre-MDT0000 complete [ 3690.984611] LustreError: 120420:0:(ldlm_lib.c:1192: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. [ 3691.023691] LustreError: 120420:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 5 previous similar messages [ 3693.009445] LustreError: 119422:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786831970 with bad export cookie 16935103863666999461 [ 3693.020474] LustreError: 119422:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 3693.023638] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3693.370229] Lustre: server umount lustre-MDT0001 complete [ 3706.237400] Lustre: server umount lustre-OST0000 complete [ 3719.574530] Lustre: server umount lustre-OST0001 complete [ 3733.375388] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 3742.606090] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3742.939994] LustreError: 123862:0:(ldlm_lib.c:1192: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. [ 3742.997047] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3746.427195] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3753.707752] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3757.380876] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3759.571940] Lustre: 125003:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3765.073645] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3767.406166] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 3770.712126] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3778.020859] LustreError: 125357:0:(ldlm_lib.c:1192: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. [ 3778.037884] LustreError: 125357:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 4 previous similar messages [ 3778.727352] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3779.942441] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 3779.957788] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 3780.039838] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 3784.596930] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3791.185147] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3794.466233] Lustre: 126872:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3799.685628] Lustre: 124593:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 3799.723601] Lustre: 124593:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 21 previous similar messages [ 3799.739198] Lustre: 124593:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3799.747196] Lustre: 124593:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3799.755283] Lustre: 124593:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 3799.764187] Lustre: 124593:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3799.770396] Lustre: 124593:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 3799.775564] Lustre: 124593:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3799.780218] Lustre: 124593:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 3799.784565] Lustre: 124593:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3799.792099] Lustre: *** cfs_fail_loc=1602, val=10*** [ 3799.792858] Lustre: 124593:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3799.792865] Lustre: 124593:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 3823.411820] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 18:14:59 (1786832099) [ 3826.293051] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3826.295791] Lustre: Skipped 3 previous similar messages [ 3833.647079] Lustre: *** cfs_fail_loc=161c, val=0*** [ 3851.833911] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 18:15:28 (1786832128) [ 3853.935516] Lustre: *** cfs_fail_loc=162e, val=0*** [ 3853.938290] Lustre: *** cfs_fail_loc=162e, val=0*** [ 3853.940645] Lustre: Skipped 7 previous similar messages [ 3865.840448] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 18:15:42 (1786832142) [ 3885.591941] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 18:16:01 (1786832161) [ 3896.007656] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 18:16:12 (1786832172) [ 3898.871856] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3898.917590] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3898.922536] Lustre: Skipped 3 previous similar messages [ 3903.777650] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.4@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:202 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 3904.612455] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.4@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 3911.377394] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 18:16:28 (1786832188) [ 3913.570637] Lustre: *** cfs_fail_loc=1616, val=0*** [ 3913.574333] Lustre: Skipped 3 previous similar messages [ 3931.089196] Lustre: 131399:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 253 < left 263, rollback = 2 [ 3931.100689] Lustre: 131399:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 125 previous similar messages [ 3931.115045] Lustre: 131399:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3931.127734] Lustre: 131399:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 3931.143484] Lustre: 131399:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 2/263/0 [ 3931.157380] Lustre: 131399:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 3931.174513] Lustre: 131399:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 1/3/2 [ 3931.188904] Lustre: 131399:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 3931.197573] Lustre: 131399:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 3931.210405] Lustre: 131399:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 3931.219836] Lustre: 131399:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3931.227292] Lustre: 131399:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 3945.128033] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 18:17:01 (1786832221) [ 3951.461120] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 18:17:07 (1786832227) [ 3962.666180] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 18:17:19 (1786832239) [ 3964.690566] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3964.697784] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3964.700119] Lustre: Skipped 1 previous similar message [ 3973.019981] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 18:17:29 (1786832249) [ 3974.369596] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3974.377915] Lustre: *** cfs_fail_loc=161e, val=0*** [ 3981.320952] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 18:17:38 (1786832258) [ 3982.563048] Lustre: *** cfs_fail_loc=1620, val=0*** [ 3992.967876] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 3994.178339] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 18:17:50 (1786832270) [ 3998.851356] Lustre: *** cfs_fail_loc=1621, val=127*** [ 3998.854328] Lustre: Skipped 1 previous similar message [ 4001.167380] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4019.634536] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 18:18:16 (1786832296) [ 4021.580938] Lustre: Failing over lustre-MDT0000 [ 4021.877753] Lustre: server umount lustre-MDT0000 complete [ 4023.418140] LustreError: 123857:0:(ldlm_lib.c:1192:target_handle_connect()) lustre-MDT0000: not available for connect from 192.168.206.4@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 4025.315463] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4025.320679] 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 [ 4025.338157] Lustre: Skipped 1 previous similar message [ 4029.293522] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4029.353157] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4029.493814] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4029.498213] Lustre: Skipped 3 previous similar messages [ 4029.518560] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4032.698907] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4033.630440] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4034.536568] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4034.556137] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4034.591359] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 4034.594334] LustreError: 123858:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 4034.597427] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 4042.131418] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 18:18:38 (1786832318) [ 4043.647943] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4043.744703] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4043.747159] Lustre: Skipped 1 previous similar message [ 4051.996691] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 18:18:48 (1786832328) [ 4053.358071] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4060.863620] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 18:18:57 (1786832337) [ 4061.940791] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4070.740178] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 18:19:07 (1786832347) [ 4080.821548] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 18:19:17 (1786832357) [ 4082.198244] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4082.202746] Lustre: Skipped 1 previous similar message [ 4090.739038] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 18:19:27 (1786832367) [ 4099.067447] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 18:19:35 (1786832375) [ 4103.573666] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4103.577774] Lustre: Skipped 2 previous similar messages [ 4114.683895] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 18:19:51 (1786832391) [ 4116.106169] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4116.108458] Lustre: Skipped 4 previous similar messages [ 4123.682197] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 18:20:00 (1786832400) [ 4151.518403] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 18:20:27 (1786832427) [ 4153.916822] LustreError: 129585:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 4162.772316] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 18:20:39 (1786832439) [ 4195.313607] Lustre: Failing over lustre-MDT0000 [ 4195.517208] Lustre: server umount lustre-MDT0000 complete [ 4198.369993] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4198.377079] 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 [ 4198.383859] LustreError: 127137:0:(ldlm_lib.c:1192: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. [ 4198.397980] Lustre: Skipped 6 previous similar messages [ 4198.435511] LustreError: 127137:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 4203.495408] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4203.590239] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4203.774630] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4203.815428] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4207.713673] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4209.130118] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4209.139198] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4209.157603] Lustre: Skipped 3 previous similar messages [ 4209.190847] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4209.243837] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 4209.245468] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 4210.205124] Lustre: 142559:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 264, rollback = 2 [ 4210.227643] Lustre: 142559:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 782 previous similar messages [ 4210.235595] Lustre: 142559:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 4210.253579] Lustre: 142559:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 782 previous similar messages [ 4210.268555] Lustre: 142559:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/264/0 [ 4210.279536] Lustre: 142559:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 782 previous similar messages [ 4210.285807] Lustre: 142559:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 1/3/0 [ 4210.297385] Lustre: 142559:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 782 previous similar messages [ 4210.303039] Lustre: 142559:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/32/1, delete: 1/1/0 [ 4210.308437] Lustre: 142559:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 782 previous similar messages [ 4210.313401] Lustre: 142559:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 4210.318527] Lustre: 142559:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 782 previous similar messages [ 4219.075970] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 18:21:35 (1786832495) [ 4229.973207] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 18:21:46 (1786832506) [ 4242.259672] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 18:21:58 (1786832518) [ 4243.407792] Lustre: *** cfs_fail_loc=1629, val=0*** [ 4243.414637] Lustre: Skipped 5 previous similar messages [ 4253.710537] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 18:22:10 (1786832530) [ 4258.438169] Lustre: Failing over lustre-MDT0000 [ 4258.585361] Lustre: server umount lustre-MDT0000 complete [ 4260.320090] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4260.322851] 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 [ 4260.340778] Lustre: Skipped 3 previous similar messages [ 4265.506821] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4265.611226] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4265.816338] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4269.307157] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4271.085988] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4271.105685] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4271.116482] Lustre: Skipped 3 previous similar messages [ 4271.130324] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4271.164804] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 4271.167602] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 4278.312647] Lustre: Failing over lustre-MDT0000 [ 4278.516803] Lustre: server umount lustre-MDT0000 complete [ 4281.311901] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4281.319048] 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 [ 4281.329136] Lustre: Skipped 3 previous similar messages [ 4285.843272] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4285.962425] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4286.185665] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4287.076249] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4289.907101] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4291.572302] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 4291.580214] Lustre: Skipped 3 previous similar messages [ 4291.615126] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 4291.654643] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:227 to 0x2c0000401:257) [ 4291.655580] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:385) [ 4297.543672] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 18:22:54 (1786832574) [ 4307.811233] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 18:23:04 (1786832584) [ 4318.270403] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 18:23:14 (1786832594) [ 4356.318820] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 18:23:52 (1786832632) [ 4368.995096] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 18:24:05 (1786832645) [ 4377.267027] LustreError: 148315:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4379.746619] Lustre: Failing over lustre-OST0000 [ 4379.855689] Lustre: server umount lustre-OST0000 complete [ 4380.328094] LustreError: 148315:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 4380.337172] LustreError: 148315:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4382.111076] LustreError: 148315:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 4382.137469] LustreError: lustre-OST0000-osc-MDT0000: operation lfsck_notify to node 0@lo failed: rc = -107 [ 4382.148817] 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 [ 4392.105820] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4392.285864] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 4393.843359] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4393.875726] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 4393.878447] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4393.890725] Lustre: Skipped 3 previous similar messages [ 4397.227551] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4404.169511] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 18:24:40 (1786832680) [ 4416.215255] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 4432.456542] Lustre: 151119:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4451.042590] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4454.812064] Lustre: 152253:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4467.463537] LustreError: 152391:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4467.496123] LustreError: 152391:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 4469.595064] Lustre: Failing over lustre-MDT0001 [ 4470.511167] LustreError: 152390:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 4470.519659] LustreError: 152390:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 4470.520150] LustreError: lustre-MDT0001-osp-MDT0000: operation out_update to node 0@lo failed: rc = -107 [ 4470.531202] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 4470.556163] Lustre: Skipped 1 previous similar message [ 4470.562687] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 4470.572718] Lustre: Skipped 2 previous similar messages [ 4470.710798] Lustre: server umount lustre-MDT0001 complete [ 4472.935091] LustreError: 152390:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 4474.338850] LustreError: 125366:0:(ldlm_lib.c:1192: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. [ 4474.357678] LustreError: 125366:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 24 previous similar messages [ 4483.144505] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4483.383075] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4483.388780] Lustre: Skipped 3 previous similar messages [ 4483.406540] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4487.159970] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4488.673968] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4488.677985] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 4488.687857] Lustre: Skipped 1 previous similar message [ 4488.699674] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4488.756585] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 4488.759185] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 4493.805945] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 18:26:10 (1786832770) [ 4505.089881] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 4518.380648] Lustre: 155123:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4536.517398] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4541.001992] Lustre: 156257:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4560.795977] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 18:27:17 (1786832837) [ 4562.320194] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 4564.336188] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 18:27:20 (1786832840) [ 4571.801829] Lustre: *** cfs_fail_loc=1631, val=0*** [ 4583.327927] Lustre: server umount lustre-MDT0000 complete [ 4585.965058] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4586.713710] LustreError: 123843:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786832864 with bad export cookie 16935103863667072212 [ 4586.720511] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4586.725976] LustreError: 123843:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4587.035243] Lustre: server umount lustre-MDT0001 complete [ 4601.393133] Lustre: server umount lustre-OST0000 complete [ 4614.296489] Lustre: server umount lustre-OST0001 complete [ 4632.416405] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 4643.024504] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4646.814636] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4654.520726] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4659.044612] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4661.791406] Lustre: 160157:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4667.955219] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4669.231790] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 4674.017388] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4679.658194] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 4682.422812] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4687.852419] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 4687.862203] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 4689.392815] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4698.841986] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4702.295445] Lustre: 162025:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4711.958339] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 18:29:48 (1786832988) [ 4713.598615] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 4715.107901] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 18:29:51 (1786832991) [ 4716.540261] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 4718.689146] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 18:29:54 (1786832994) [ 4720.065885] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 4721.957818] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 18:29:58 (1786832998) [ 4723.672944] Lustre: 162553:0:(osd_internal.h:1461:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 4723.680733] Lustre: 162553:0:(osd_internal.h:1461:osd_trans_exec_op()) Skipped 1625 previous similar messages [ 4723.687237] Lustre: 162553:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4723.692439] Lustre: 162553:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1625 previous similar messages [ 4723.699038] Lustre: 162553:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4723.704856] Lustre: 162553:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1625 previous similar messages [ 4723.709957] Lustre: 162553:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4723.715048] Lustre: 162553:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1625 previous similar messages [ 4723.720161] Lustre: 162553:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 4723.730281] Lustre: 162553:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1625 previous similar messages [ 4723.735992] Lustre: 162553:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4723.744622] Lustre: 162553:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1625 previous similar messages [ 4733.367642] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 18:30:09 (1786833009) [ 4746.644295] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 18:30:23 (1786833023) [ 4761.055914] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 18:30:37 (1786833037) [ 4776.005746] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 18:30:52 (1786833052) [ 4828.884650] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 18:31:44 (1786833104) [ 4862.896310] Lustre: *** cfs_fail_loc=1632, val=0*** [ 4878.221531] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 18:32:34 (1786833154) [ 4880.822646] Lustre: Failing over lustre-MDT0001 [ 4881.082480] Lustre: server umount lustre-MDT0001 complete [ 4882.401286] 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 [ 4882.421934] Lustre: Skipped 8 previous similar messages [ 4888.189503] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4888.659934] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 4888.660216] Lustre: lustre-MDT0001: Aborting client recovery [ 4888.686357] LustreError: 166613:0:(ldlm_lib.c:3004:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 4888.697559] Lustre: 166638:0:(ldlm_lib.c:2404:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 4888.706459] Lustre: 166638:0:(genops.c:1622:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 86fcce5b-5d72-43ce-b3e8-c0c2b96ba507@ [ 4888.713992] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 4888.719489] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 4888.727563] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 4888.774567] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 4888.776466] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:161) [ 4892.729038] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4893.678121] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 4893.691552] Lustre: lustre-MDT0001-osp-MDT0000: Connection restored to 0@lo (at 0@lo) [ 4893.702814] Lustre: Skipped 4 previous similar messages [ 4901.865513] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 4902.110978] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 4908.214284] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 18:33:04 (1786833184) [ 4916.638936] Lustre: *** cfs_fail_loc=1600, val=3*** [ 4919.155254] Lustre: Failing over lustre-MDT0000 [ 4919.191382] LustreError: lustre-MDT0000-osp-MDT0001: operation out_update to node 0@lo failed: rc = -107 [ 4919.209655] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4919.406808] Lustre: server umount lustre-MDT0000 complete [ 4927.528922] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4927.596543] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4927.823841] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4927.833956] Lustre: Skipped 2 previous similar messages [ 4931.173637] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4931.838594] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4933.097598] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4933.121242] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 4933.172431] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 4933.174543] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 4942.292938] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 18:33:38 (1786833218) [ 4966.933931] Lustre: Failing over lustre-OST0000 [ 4967.030545] Lustre: server umount lustre-OST0000 complete [ 4972.354931] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 4981.813773] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 4982.367868] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 4983.130683] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 4987.556697] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4995.215569] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 4995.434896] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 5000.476720] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 5000.668805] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 5007.173322] Lustre: DEBUG MARKER: oleg604-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffff999e89a3a000.ost_server_uuid 50 [ 5009.129353] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff999e89a3a000.ost_server_uuid in FULL state after 0 sec [ 5064.161773] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5064.175834] Lustre: Skipped 6 previous similar messages [ 5069.280447] LustreError: 159011:0:(ldlm_lib.c:1192: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. [ 5069.306358] LustreError: 159011:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 39 previous similar messages [ 5069.582307] Lustre: server umount lustre-MDT0000 complete [ 5077.145542] LustreError: 158996:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786833355 with bad export cookie 16935103863667154476 [ 5077.148979] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5077.155866] LustreError: 158996:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 5077.596766] Lustre: server umount lustre-MDT0001 complete [ 5095.903412] Lustre: 106772:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786833357/real 1786833357] req@ffff8bb53537c000 x1873628702305792/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786833373 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5098.341756] Lustre: server umount lustre-OST0000 complete [ 5098.975360] Lustre: 106770:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786833360/real 1786833360] req@ffff8bb53537ea00 x1873628702306176/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786833376 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5100.063203] Lustre: 106772:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786833362/real 1786833362] req@ffff8bb529609180 x1873628702306432/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786833378 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5104.607086] Lustre: 106769:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786833366/real 1786833366] req@ffff8bb534849880 x1873628702306944/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786833382 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5106.566573] Lustre: server umount lustre-OST0001 complete [ 5122.312578] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing unload_modules_local [ 5125.021739] Key type lgssc unregistered [ 5125.296434] LNet: 175747:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5125.306825] LNetError: 175747:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5125.323669] LNet: Removed LNI 192.168.206.104@tcp [ 5126.295574] Key type .llcrypt unregistered [ 5126.297338] Key type ._llcrypt unregistered [ 5148.346845] Key type ._llcrypt registered [ 5148.349746] Key type .llcrypt registered [ 5148.432934] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_hostid [ 5165.324632] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 5166.418574] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 5166.455110] alg: No test for adler32 (adler32-zlib) [ 5167.470710] Lustre: Lustre: Build Version: 2.17.57_3_g928f38d [ 5167.806637] LNet: Added LNI 192.168.206.104@tcp [8/256/0/180] [ 5169.503175] Key type lgssc registered [ 5170.468273] Lustre: Echo OBD driver; http://www.lustre.org/ [ 5218.850786] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing load_modules_local [ 5232.271509] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 5232.309858] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5233.606126] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 5233.699295] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 5233.864995] Lustre: lustre-MDT0000: new disk, initializing [ 5233.940289] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 5233.958829] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 5238.866959] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5250.721360] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5250.864869] Lustre: 180201: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 [ 5250.901756] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 5250.908726] Lustre: Skipped 1 previous similar message [ 5250.992608] Lustre: lustre-MDT0001: new disk, initializing [ 5251.067166] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5251.095808] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 5251.109576] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 5254.689599] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5259.038986] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 5268.742372] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5268.995073] Lustre: lustre-OST0000: new disk, initializing [ 5268.999766] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 5269.009019] Lustre: 182139:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5269.089350] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5273.626939] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 5273.640107] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 5273.706322] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 5274.370522] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5287.952084] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 5288.173327] Lustre: lustre-OST0001: new disk, initializing [ 5288.181228] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 5288.191970] Lustre: 183162:0:(osd_compat.c:1352:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 5288.291303] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 5294.417638] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5296.676880] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 5296.689918] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 5296.722433] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 5305.624583] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5310.911538] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 5315.835474] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 18:39:52 (1786833592) === [ 5317.239209] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 5052 sec ========= 18:39:53 (1786833593) [ 5318.805755] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 18:39:55 (1786833595) === [ 5321.585753] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 18:39:58 (1786833598) === [ 5327.330412] 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 [ 5327.340671] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5327.351121] Lustre: Skipped 3 previous similar messages [ 5327.364286] Lustre: Skipped 3 previous similar messages [ 5331.323521] Lustre: server umount lustre-MDT0000 complete [ 5337.571844] LustreError: 183454:0:(ldlm_lib.c:1192: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. [ 5337.595123] LustreError: 183454:0:(ldlm_lib.c:1192:target_handle_connect()) Skipped 8 previous similar messages [ 5339.228088] LustreError: 180190:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1786833617 with bad export cookie 2188305420889128846 [ 5339.228236] LustreError: MGC192.168.206.104@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5339.246264] LustreError: 180190:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 5339.656094] Lustre: server umount lustre-MDT0001 complete [ 5357.602962] Lustre: server umount lustre-OST0000 complete [ 5358.559134] Lustre: 177361:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786833620/real 1786833620] req@ffff8bb40b76bb80 x1873630666504192/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786833636 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5358.590830] 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 [ 5360.095154] Lustre: 177360:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786833622/real 1786833622] req@ffff8bb40b769880 x1873630666504448/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786833638 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5363.167692] Lustre: 177360:0:(client.c:2490:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1786833625/real 1786833625] req@ffff8bb5353a2680 x1873630666504704/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1786833641 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 5364.424996] Lustre: server umount lustre-OST0001 complete [ 5378.677754] Lustre: DEBUG MARKER: oleg604-server.virtnet: executing unload_modules_local [ 5381.335591] Key type lgssc unregistered [ 5381.638852] LNet: 186637:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 5381.651480] LNetError: 186637:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 5381.661787] LNet: Removed LNI 192.168.206.104@tcp [ 5382.341147] Key type .llcrypt unregistered [ 5382.348240] Key type ._llcrypt unregistered