[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-8.fc42 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 466885002 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 0x00000000BFFE2439 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE22D5 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 002295 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE2349 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE23D9 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2411 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe22d5-0xbffe2348] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe22d4] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe2349-0xbffe23d8] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe23d9-0xbffe2410] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2411-0xbffe2438] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 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.001012] APIC: Switch to symmetric I/O mode setup [ 0.003256] x2apic enabled [ 0.004011] Switched APIC routing to physical x2apic. [ 0.005014] kvm-guest: setup PV IPIs [ 0.008000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.008000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.008025] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.009014] pid_max: default: 32768 minimum: 301 [ 0.010149] LSM: Security Framework initializing [ 0.011071] Yama: becoming mindful. [ 0.012041] SELinux: Initializing. [ 0.013119] *** VALIDATE selinux *** [ 0.021836] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.026598] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.027187] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028127] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.030129] *** VALIDATE tmpfs *** [ 0.031484] *** VALIDATE proc *** [ 0.032275] *** VALIDATE cgroup *** [ 0.033010] *** VALIDATE cgroup2 *** [ 0.034275] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.035169] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.036012] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037035] Spectre V2 : User space: Vulnerable [ 0.038013] Speculative Store Bypass: Vulnerable [ 0.041112] debug: unmapping init [mem 0xffffffff92859000-0xffffffff92860fff] [ 0.044000] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044740] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045027] ... version: 2 [ 0.046013] ... bit width: 48 [ 0.047016] ... generic registers: 4 [ 0.048014] ... value mask: 0000ffffffffffff [ 0.049018] ... max period: 00007fffffffffff [ 0.050016] ... fixed-purpose events: 3 [ 0.051016] ... event mask: 000000070000000f [ 0.052337] rcu: Hierarchical SRCU implementation. [ 0.054496] smp: Bringing up secondary CPUs ... [ 0.055650] x86: Booting SMP configuration: [ 0.056027] .... node #0, CPUs: #1 #2 #3 [ 0.060089] smp: Brought up 1 node, 4 CPUs [ 0.062032] smpboot: Max logical packages: 1 [ 0.063017] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.137027] node 0 deferred pages initialised in 72ms [ 0.139138] devtmpfs: initialized [ 0.141318] x86/mm: Memory block size: 128MB [ 0.144641] gcov: version magic: 0x41383552 [ 0.147368] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.148091] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.149295] pinctrl core: initialized pinctrl subsystem [ 0.150341] [ 0.150790] ************************************************************* [ 0.151017] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.152013] ** ** [ 0.153016] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.154013] ** ** [ 0.155014] ** This means that this kernel is built to expose internal ** [ 0.156013] ** IOMMU data structures, which may compromise security on ** [ 0.157013] ** your system. ** [ 0.158015] ** ** [ 0.159015] ** If you see this message and you are not debugging the ** [ 0.160013] ** kernel, report this immediately to your vendor! ** [ 0.161011] ** ** [ 0.162012] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.163009] ************************************************************* [ 0.164692] NET: Registered protocol family 16 [ 0.165467] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.166044] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.167037] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.168471] cpuidle: using governor menu [ 0.169412] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.171427] PCI: Using configuration type 1 for base access [ 0.172111] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.178138] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.179011] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.180143] cryptd: max_cpu_qlen set to 1000 [ 0.181261] ACPI: Added _OSI(Module Device) [ 0.182017] ACPI: Added _OSI(Processor Device) [ 0.182951] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.183012] ACPI: Added _OSI(Processor Aggregator Device) [ 0.187106] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.190177] ACPI: Interpreter enabled [ 0.191051] ACPI: PM: (supports S0 S3 S4 S5) [ 0.191966] ACPI: Using IOAPIC for interrupt routing [ 0.192125] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.193403] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.202385] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.203048] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.204023] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.205083] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.207721] acpiphp: Slot [2] registered [ 0.208116] acpiphp: Slot [5] registered [ 0.209117] acpiphp: Slot [6] registered [ 0.210108] acpiphp: Slot [7] registered [ 0.211115] acpiphp: Slot [8] registered [ 0.212100] acpiphp: Slot [9] registered [ 0.213120] acpiphp: Slot [10] registered [ 0.214098] acpiphp: Slot [3] registered [ 0.215109] acpiphp: Slot [4] registered [ 0.216062] acpiphp: Slot [11] registered [ 0.217076] acpiphp: Slot [12] registered [ 0.218077] acpiphp: Slot [13] registered [ 0.219129] acpiphp: Slot [14] registered [ 0.220087] acpiphp: Slot [15] registered [ 0.221100] acpiphp: Slot [16] registered [ 0.222077] acpiphp: Slot [17] registered [ 0.223081] acpiphp: Slot [18] registered [ 0.224068] acpiphp: Slot [19] registered [ 0.225111] acpiphp: Slot [20] registered [ 0.226097] acpiphp: Slot [21] registered [ 0.227080] acpiphp: Slot [22] registered [ 0.228070] acpiphp: Slot [23] registered [ 0.229096] acpiphp: Slot [24] registered [ 0.230089] acpiphp: Slot [25] registered [ 0.231076] acpiphp: Slot [26] registered [ 0.232128] acpiphp: Slot [27] registered [ 0.233134] acpiphp: Slot [28] registered [ 0.234135] acpiphp: Slot [29] registered [ 0.235097] acpiphp: Slot [30] registered [ 0.236090] acpiphp: Slot [31] registered [ 0.237089] PCI host bridge to bus 0000:00 [ 0.238020] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.239025] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.240033] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.241027] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.242026] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.243038] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.244229] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.245971] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.247292] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.252432] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.255064] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.256021] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.257012] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.258012] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.259568] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.260885] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.261043] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.262684] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.264016] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.269631] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.271013] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.273977] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.276019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.279018] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.287018] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.292171] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.298071] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.305025] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.318015] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.329170] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.333015] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.337014] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.347015] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.354847] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.365018] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.375019] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.392017] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.402000] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.409019] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.415125] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.431015] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.438916] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.447019] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.452018] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.470019] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.484963] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.487417] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.490421] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.492429] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.495261] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.501038] iommu: Default domain type: Passthrough [ 0.502356] SCSI subsystem initialized [ 0.503094] ACPI: bus type USB registered [ 0.504046] usbcore: registered new interface driver usbfs [ 0.505074] usbcore: registered new interface driver hub [ 0.506091] usbcore: registered new device driver usb [ 0.508177] pps_core: LinuxPPS API ver. 1 registered [ 0.510017] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.513069] PTP clock support registered [ 0.516079] EDAC MC: Ver: 3.0.0 [ 0.518240] PCI: Using ACPI for IRQ routing [ 0.519712] NetLabel: Initializing [ 0.521016] NetLabel: domain hash size = 128 [ 0.523014] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.525089] NetLabel: unlabeled traffic allowed by default [ 0.527483] vgaarb: loaded [ 0.530345] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.532017] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.543956] clocksource: Switched to clocksource kvm-clock [ 0.637191] VFS: Disk quotas dquot_6.6.0 [ 0.638795] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.640301] *** VALIDATE ramfs *** [ 0.641168] *** VALIDATE hugetlbfs *** [ 0.642148] pnp: PnP ACPI init [ 0.643801] pnp: PnP ACPI: found 6 devices [ 0.658676] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.660665] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.662025] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.663310] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.665291] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.667187] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.668622] NET: Registered protocol family 2 [ 0.670333] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.673458] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.675694] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.679736] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.681945] TCP: Hash tables configured (established 65536 bind 65536) [ 0.683715] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.685622] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.687641] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.689685] NET: Registered protocol family 1 [ 0.691658] RPC: Registered named UNIX socket transport module. [ 0.692895] RPC: Registered udp transport module. [ 0.694170] RPC: Registered tcp transport module. [ 0.695091] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.696405] NET: Registered protocol family 44 [ 0.697318] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.699471] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.701561] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.704077] PCI: CLS 0 bytes, default 64 [ 0.705649] Unpacking initramfs... [ 2.055498] debug: unmapping init [mem 0xffff9ce57cc54000-0xffff9ce57ffbffff] [ 2.058697] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.060304] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.062977] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.617849] Initialise system trusted keyrings [ 2.619966] Key type blacklist registered [ 2.622071] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.634371] zbud: loaded [ 2.639616] *** VALIDATE nfs *** [ 2.642271] *** VALIDATE nfs4 *** [ 2.643966] pstore: using deflate compression [ 2.647738] Platform Keyring initialized [ 2.768696] NET: Registered protocol family 38 [ 2.770098] Key type asymmetric registered [ 2.771383] Asymmetric key parser 'x509' registered [ 2.773537] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 2.777067] io scheduler mq-deadline registered [ 2.778606] io scheduler kyber registered [ 2.779828] io scheduler bfq registered [ 2.781399] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 2.783873] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 2.786300] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 2.789797] ACPI: Power Button [PWRF] [ 2.793522] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 2.799349] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 2.810247] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 2.816163] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 2.829883] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 2.855541] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 2.881650] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 2.885192] Non-volatile memory driver v1.3 [ 2.886358] Linux agpgart interface v0.103 [ 2.911870] virtio_blk virtio1: [vda] 134104 512-byte logical blocks (68.7 MB/65.5 MiB) [ 2.913960] vda: detected capacity change from 0 to 68661248 [ 2.937213] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 2.939136] vdb: detected capacity change from 0 to 1073741824 [ 2.959332] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 2.962778] vdc: detected capacity change from 0 to 2621440000 [ 2.985235] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 2.989838] vdd: detected capacity change from 0 to 2621440000 [ 3.007521] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.009852] vde: detected capacity change from 0 to 4294967296 [ 3.023272] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.026057] vdf: detected capacity change from 0 to 4294967296 [ 3.035185] libphy: Fixed MDIO Bus: probed [ 3.043738] usbcore: registered new interface driver usbserial_generic [ 3.045798] usbserial: USB Serial support registered for generic [ 3.047651] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.053210] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.056354] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.059994] mousedev: PS/2 mouse device common for all mice [ 3.064412] rtc_cmos 00:05: RTC can wake from S4 [ 3.069256] rtc_cmos 00:05: registered as rtc0 [ 3.069318] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.070629] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.079550] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.079846] intel_pstate: CPU model not supported [ 3.086405] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.095795] hid: raw HID events driver (C) Jiri Kosina [ 3.099065] usbcore: registered new interface driver usbhid [ 3.102016] usbhid: USB HID core driver [ 3.104109] drop_monitor: Initializing network drop monitor service [ 3.107674] Initializing XFRM netlink socket [ 3.109490] NET: Registered protocol family 10 [ 3.112545] Segment Routing with IPv6 [ 3.114182] NET: Registered protocol family 17 [ 3.116642] mpls_gso: MPLS GSO support [ 3.124234] RAS: Correctable Errors collector initialized. [ 3.126153] AVX version of gcm_enc/dec engaged. [ 3.127278] AES CTR mode by8 optimization enabled [ 3.207205] sched_clock: Marking stable (3207182183, 0)->(4232103270, -1024921087) [ 3.211656] registered taskstats version 1 [ 3.213867] Loading compiled-in X.509 certificates [ 3.215205] zswap: loaded using pool lzo/zbud [ 3.237788] Key type big_key registered [ 3.250925] Key type encrypted registered [ 3.252863] ima: No TPM chip found, activating TPM-bypass! [ 3.254863] ima: Allocated hash algorithm: sha1 [ 3.256356] ima: No architecture policies found [ 3.258202] evm: Initialising EVM extended attributes: [ 3.259944] evm: security.selinux [ 3.260698] evm: security.ima [ 3.261281] evm: security.capability [ 3.262061] evm: HMAC attrs: 0x1 [ 3.263554] rtc_cmos 00:05: setting system clock to 2026-01-16 09:11:04 UTC (1768554664) [ 3.267236] debug: unmapping init [mem 0xffffffff93803000-0xffffffff939fffff] [ 3.269400] debug: unmapping init [mem 0xffffffff92582000-0xffffffff92858fff] [ 3.277092] Write protecting the kernel read-only data: 28672k [ 3.280244] debug: unmapping init [mem 0xffffffff90c03000-0xffffffff90dfffff] [ 3.282591] debug: unmapping init [mem 0xffffffff91514000-0xffffffff915fffff] [ 3.313724] 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.321506] systemd[1]: Detected virtualization kvm. [ 3.323499] systemd[1]: Detected architecture x86-64. [ 3.325198] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.350420] systemd[1]: No hostname configured. [ 3.351638] systemd[1]: Set hostname to . [ 3.353156] random: systemd: uninitialized urandom read (16 bytes read) [ 3.354883] systemd[1]: Initializing machine ID from random generator. [ 3.391074] random: ln: uninitialized urandom read (6 bytes read) [ 3.473449] random: systemd: uninitialized urandom read (16 bytes read) [ 3.475424] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 3.479380] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 3.485163] systemd[1]: Reached target Local Encrypted Volumes. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Listening on udev Control Socket. [ OK ] Reached target Paths. [ OK ] Listening on Journal Socket. Starting Apply Kernel Variables... [ OK ] Started Memstrack Anylazing Service. Starting Setup Virtual Console... Starting Create list of required st…ce nodes for the current kernel... [ OK ] Reached target Local File Systems. Starting Create Volatile Files and Directories... [ OK ] Reached target Slices. [ OK ] Reached target Timers. [ OK ] Reached target Sockets. [ OK ] Reached target Initrd Root Device. Starting Journal Service... [ OK ] Started Apply Kernel Variables. [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.053504] device-mapper: uevent: version 1.0.3 [ 4.056551] device-mapper: ioctl: 4.46.0-ioctl (2022-02-22) initialised: dm-devel@redhat.com [ OK ] Started dracut pre-udev hook. Starting udev Kernel Device Manager... [ OK ] Started udev Kernel Device Manager. Starting dracut pre-trigger hook... [ OK ] Started dracut pre-trigger hook. Starting udev Coldplug all Devices... Mounting Kernel Configuration File System... [ OK ] Mounted Kernel Configuration File System. [ OK ] Started udev Coldplug all Devices. Starting dracut initqueue hook... [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ 4.789726] virtio_net virtio0 ens2: renamed from eth0 [ 4.807583] scsi host0: ata_piix [ 4.813484] random: fast init done [ 4.817745] scsi host1: ata_piix [ 4.821780] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 4.825378] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 8.626664] dracut-initqueue[582]: RTNETLINK answers: File exists [ 9.766265] random: crng init done [ 9.767757] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. Mounting /sysroot... [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. [ 10.203112] 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 Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Slices. [ OK ] Stopped target Paths. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. [ OK ] Stopped target Local Encrypted Volumes. [ OK ] Stopped Dispatch Password Requests to Console Directory Watch. [ OK ] Stopped Create Volatile Files and Directories. [ OK ] Stopped target Local File Systems. Stopping udev Kernel Device Manager... [ OK ] Stopped target Sockets. [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Kernel Socket. [ OK ] Closed udev Control Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.336306] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.600108] SELinux: Disabled at runtime. [ 11.661611] systemd[1]: systemd 239 (239-82.el8_10.5) running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy) [ 11.670138] systemd[1]: Detected virtualization kvm. [ 11.672066] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.139718] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.143356] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.149840] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.154157] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.157324] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.164046] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.171496] systemd[1]: Starting Create list of required static device nodes for the current kernel... Starting Create list of required st…ce nodes for the current kernel... Mounting Huge Pages File System... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Reached target RPC Port Mapper. Starting Apply Kernel Variables... [ OK ] Created slice User and Session Slice. [ OK ] Created slice system-getty.slice. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd File Systems. Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target rpc_pipefs.target. [ OK ] Reached target Slices. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [FAILED] Failed to set up automount Arbitrar…rmats File System Automount Point. See 'systemctl status proc-sys-fs-binfmt_misc.automount' for details. Mounting Kernel Debug File System... [ OK ] Created slice system-serial\x2dgetty.slice.[ 12.261275] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Listening on udev Kernel Socket. Starting Remount Root and Kernel File Systems... [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on initctl Compatibility Named Pipe. [ OK ] Listening on udev Control Socket. Starting udev Coldplug all Devices... Mounting POSIX Message Queue File System... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Stopped target Initrd Root File System. [ OK ] Listening on Process Core Dump Socket. [ OK ] Started Journal Service. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Mounted Huge Pages File System. [ OK ] Started Apply Kernel Variables. [ OK ] Activated swap /dev/disk/by-label/SWAP. [ OK ] Mounted Kernel Debug File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ OK ] Mounted POSIX Message Queue File System. Starting Configure read-only root support... [ OK ] Reached target Swap. Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /home/green/git/lustre-release... Mounting /mnt... [ OK ] Mounted /mnt. [ OK ] Started udev Coldplug all Devices. [ 12.606602] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 12.890229] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 12.904305] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 13.048644] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 13.061154] EDAC sbridge: Ver: 1.1.2 [ 14.393683] Key type dns_resolver registered [ 14.697993] NFS: Registering the id_resolver key type [ 14.700286] Key type id_resolver registered [ 14.702032] Key type id_legacy registered [ OK ] Started Configure read-only root support. [ 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... Starting Load/Save Random Seed... [ OK ] Started Mark the need to relabel after reboot. [ OK ] Started Load/Save Random Seed. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting RPC Bind... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started dnf makecache --timer. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting Restore /run/initramfs on shutdown... [ OK ] Started irqbalance daemon. Starting Login Service... [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Reached target Timers. [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Dynamic System Tuning Daemon... [ OK ] Started OpenSSH server daemon. Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Command Scheduler. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Started Serial Getty on ttyS1. [ OK ] Reached target Login Prompts. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting System Logging Service... Starting Notify NFS peers of a restart... Starting Crash recovery kernel arming... [ OK ] Started Notify NFS peers of a restart. [ OK ] Started System Logging Service. Starting Authorization Manager... Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg210-server login: [ 42.253959] hrtimer: interrupt took 4076194 ns [ 74.057806] libcfs: loading out-of-tree module taints kernel. [ 74.102846] Key type ._llcrypt registered [ 74.104846] Key type .llcrypt registered [ 74.207911] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [ 95.859443] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 98.291402] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 98.307145] alg: No test for adler32 (adler32-zlib) [ 99.790841] Lustre: Lustre: Build Version: 2.17.50_30_gc0571ea [ 100.380904] LNet: Added LNI 192.168.202.110@tcp [8/256/0/180] [ 102.058506] Key type lgssc registered [ 104.389231] Lustre: Echo OBD driver; http://www.lustre.org/ [ 123.087991] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 162.659682] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 177.079569] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 177.128535] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 178.549876] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 178.626956] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 178.812763] Lustre: lustre-MDT0000: new disk, initializing [ 178.930863] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 178.955742] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 184.222242] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 198.166450] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 198.342631] Lustre: 6502:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 198.404072] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 198.414636] Lustre: Skipped 1 previous similar message [ 198.611423] Lustre: lustre-MDT0001: new disk, initializing [ 198.723987] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 198.770097] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 198.788304] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 203.399139] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 208.927574] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 218.867171] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 219.162106] Lustre: lustre-OST0000: new disk, initializing [ 219.176094] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 219.281065] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 220.105239] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 220.114439] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 220.225994] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 225.415778] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 241.181294] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 241.334304] Lustre: lustre-OST0001: new disk, initializing [ 241.338732] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 241.382722] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 248.757651] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 248.891108] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 248.904379] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 248.984882] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 261.851675] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 271.792308] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 283.205781] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing check_logdir /tmp/testlogs/ [ 288.009686] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing yml_node [ 292.569365] Lustre: DEBUG MARKER: Client: 2.17.50.30 [ 295.004771] Lustre: DEBUG MARKER: MDS: 2.17.50.30 [ 297.871743] Lustre: DEBUG MARKER: OSS: 2.17.50.30 [ 299.694499] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Fri Jan 16 04:15:59 EST 2026 [ 319.188262] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 329.539403] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 341.475642] 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 [ 341.480045] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 341.498343] Lustre: Skipped 1 previous similar message [ 341.519772] Lustre: Skipped 3 previous similar messages [ 344.570950] LustreError: 12569:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 344.683159] Lustre: server umount lustre-MDT0000 complete [ 351.730323] LustreError: 6511:0:(ldlm_lib.c:1179: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. [ 351.747323] LustreError: 6511:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 353.551789] LustreError: 6494:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768555014 with bad export cookie 6785067048829856931 [ 353.560363] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 353.571013] LustreError: 6494:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 353.685574] LustreError: 13021:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 353.689317] LustreError: 13021:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 353.827874] Lustre: server umount lustre-MDT0001 complete [ 372.004212] LustreError: 13471:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 372.008091] LustreError: 13471:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 372.188943] Lustre: server umount lustre-OST0000 complete [ 373.224453] Lustre: 3653:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768555018/real 1768555018] req@ffff9ce5ede46a00 x1854464077178112/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768555034 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 373.262801] 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 [ 373.281149] Lustre: Skipped 2 previous similar messages [ 375.072217] Lustre: 3656:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768555020/real 1768555020] req@ffff9ce5ede44e00 x1854464077178368/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768555036 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 378.337944] Lustre: 3654:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768555023/real 1768555023] req@ffff9ce5f5675f80 x1854464077178624/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768555039 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 381.853776] LustreError: 13924:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 381.864488] LustreError: 13924:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 382.051303] Lustre: server umount lustre-OST0001 complete [ 398.608664] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing unload_modules_local [ 401.739244] Key type lgssc unregistered [ 402.091815] LNet: 14706:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 402.104880] LNetError: 14706:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 402.123455] LNet: Removed LNI 192.168.202.110@tcp [ 403.044257] Key type .llcrypt unregistered [ 403.049944] Key type ._llcrypt unregistered [ 426.633635] Key type ._llcrypt registered [ 426.635313] Key type .llcrypt registered [ 426.777157] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [ 439.999991] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 441.217418] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 441.242640] alg: No test for adler32 (adler32-zlib) [ 442.522827] Lustre: Lustre: Build Version: 2.17.50_30_gc0571ea [ 442.993774] LNet: Added LNI 192.168.202.110@tcp [8/256/0/180] [ 444.704205] Key type lgssc registered [ 445.945411] Lustre: Echo OBD driver; http://www.lustre.org/ [ 510.017907] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 524.845789] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 524.876845] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 526.295545] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 526.349802] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 526.468179] Lustre: lustre-MDT0000: new disk, initializing [ 526.580738] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 526.622043] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 531.879256] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 546.304174] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 546.446042] Lustre: 19089:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 546.483027] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 546.487116] Lustre: Skipped 1 previous similar message [ 546.580630] Lustre: lustre-MDT0001: new disk, initializing [ 546.673044] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 546.713511] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 546.725367] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 552.233815] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 557.887395] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 569.249538] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 569.587176] Lustre: lustre-OST0000: new disk, initializing [ 569.590837] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 569.669423] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 576.032637] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 576.043918] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 576.143684] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 576.467380] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 590.140179] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 590.282663] Lustre: lustre-OST0001: new disk, initializing [ 590.292996] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 590.362826] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 596.449668] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 597.533930] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 597.544349] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 597.611747] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 608.212109] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 618.108440] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 631.432390] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 04:21:31 (1768555291) === [ 634.341496] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 04:21:34 (1768555294) [ 634.709585] Lustre: 19097:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 634.723741] Lustre: 19097:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 634.734235] Lustre: 19097:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 634.747394] Lustre: 19097:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 634.756918] Lustre: 19097:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 634.765403] Lustre: 19097:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 635.298206] Lustre: 19097:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 635.313258] Lustre: 19097:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 11 previous similar messages [ 635.319480] Lustre: 19097:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 635.332354] Lustre: 19097:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 635.348256] Lustre: 19097:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 635.363666] Lustre: 19097:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 635.375856] Lustre: 19097:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 2/12/0, punch: 0/0/0, quota 1/3/0 [ 635.384123] Lustre: 19097:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 635.389942] Lustre: 19097:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 635.401662] Lustre: 19097:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 635.408263] Lustre: 19097:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 635.414595] Lustre: 19097:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 636.373253] Lustre: 19098:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 636.387952] Lustre: 19098:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 41 previous similar messages [ 636.399249] Lustre: 19098:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 636.405784] Lustre: 19098:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 636.413220] Lustre: 19098:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 636.423464] Lustre: 19098:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 636.430103] Lustre: 19098:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 2/12/0, punch: 0/0/0, quota 1/3/0 [ 636.436778] Lustre: 19098:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 636.443432] Lustre: 19098:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 636.464360] Lustre: 19098:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 636.474954] Lustre: 19098:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 636.487208] Lustre: 19098:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 41 previous similar messages [ 638.376746] Lustre: 19098:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 638.387064] Lustre: 19098:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 104 previous similar messages [ 638.462630] Lustre: 19097:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 638.468811] Lustre: 19097:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 638.476852] Lustre: 19097:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 638.493350] Lustre: 19097:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 638.506324] Lustre: 19097:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 2/12/0, punch: 0/0/0, quota 1/3/0 [ 638.513839] Lustre: 19097:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 638.533563] Lustre: 19097:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 638.542236] Lustre: 19097:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 638.552685] Lustre: 19097:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 638.564176] Lustre: 19097:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 107 previous similar messages [ 642.955989] Lustre: *** cfs_fail_loc=1600, val=3*** [ 645.166635] Lustre: 23173:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 260 < left 274, rollback = 2 [ 645.183480] Lustre: 23173:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 121 previous similar messages [ 645.192517] Lustre: 23173:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 645.199428] Lustre: 23173:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 118 previous similar messages [ 645.203890] Lustre: 23173:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/274/0 [ 645.211524] Lustre: 23173:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 118 previous similar messages [ 645.226896] Lustre: 23173:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 645.234487] Lustre: 23173:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 118 previous similar messages [ 645.245554] Lustre: 23173:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 645.251416] Lustre: 23173:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 118 previous similar messages [ 645.264808] Lustre: 23173:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 645.275907] Lustre: 23173:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 118 previous similar messages [ 647.330744] Lustre: *** cfs_fail_loc=1600, val=3*** [ 660.357548] Lustre: 23174:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 660.359843] Lustre: 23390:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 660.385519] Lustre: 23174:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 64 previous similar messages [ 660.385563] Lustre: 23174:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 660.385567] Lustre: 23174:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 63 previous similar messages [ 660.385574] Lustre: 23174:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 660.385577] Lustre: 23174:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 63 previous similar messages [ 660.385582] Lustre: 23174:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 660.385586] Lustre: 23174:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 63 previous similar messages [ 660.385591] Lustre: 23174:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 660.385596] Lustre: 23174:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 63 previous similar messages [ 660.531435] Lustre: 23390:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 66 previous similar messages [ 664.552427] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 664.555762] 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 [ 664.590132] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 669.153848] 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 [ 669.156472] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 669.176468] Lustre: Skipped 1 previous similar message [ 669.191208] Lustre: Skipped 1 previous similar message [ 670.535907] LustreError: 24052:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 670.912515] Lustre: server umount lustre-MDT0000 complete [ 675.454500] LustreError: 19082:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768555336 with bad export cookie 9632790624371980534 [ 675.456442] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 675.479727] LustreError: 19082:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 675.724741] LustreError: 24254:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 675.742210] LustreError: 24254:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 676.200286] Lustre: server umount lustre-MDT0001 complete [ 691.605419] LustreError: 24457:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 691.612896] LustreError: 24457:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 691.796862] Lustre: server umount lustre-OST0000 complete [ 695.777588] Lustre: 16268:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768555341/real 1768555341] req@ffff9ce4c255df80 x1854464436848640/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768555357 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 695.835220] 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 [ 695.855465] Lustre: Skipped 1 previous similar message [ 696.669666] LustreError: 24659:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 696.681267] LustreError: 24659:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 696.910797] Lustre: server umount lustre-OST0001 complete [ 707.048337] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 04:22:46 (1768555366) [ 721.125657] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 731.708735] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 732.236750] LustreError: 26029:0:(ldlm_lib.c:1179: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. [ 732.258482] LustreError: 26029:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 5 previous similar messages [ 732.352872] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 737.113194] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 737.765493] LustreError: 26029:0:(ldlm_lib.c:1179: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. [ 741.877177] LustreError: 26029:0:(ldlm_lib.c:1179: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. [ 746.977692] LustreError: 26029:0:(ldlm_lib.c:1179: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. [ 747.221492] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 747.733551] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 754.207779] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 757.403382] Lustre: 27134:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 766.235431] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 766.402658] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 772.518773] LustreError: 27490:0:(ldlm_lib.c:1179: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. [ 772.689608] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 777.670785] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:41 to 0x280000401:65) [ 782.827406] LustreError: 27825:0:(ldlm_lib.c:1179: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. [ 782.864026] LustreError: 27825:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 783.454210] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 785.682878] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 789.769363] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 797.718290] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 801.733686] Lustre: 28979:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 808.178568] Lustre: 26023:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 808.186720] Lustre: 26023:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 4 previous similar messages [ 808.190423] Lustre: 26023:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 808.193566] Lustre: 26023:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 2 previous similar messages [ 808.198034] Lustre: 26023:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 808.202792] Lustre: 26023:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 808.207896] Lustre: 26023:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 808.212829] Lustre: 26023:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 808.218371] Lustre: 26023:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 808.223550] Lustre: 26023:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 808.228181] Lustre: 26023:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 808.231094] Lustre: 26023:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 5 previous similar messages [ 814.008732] Lustre: *** cfs_fail_loc=1501, val=0*** [ 822.188707] Lustre: Failing over lustre-MDT0000 [ 822.295935] LustreError: 29369:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 822.304771] LustreError: 29369:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 824.289602] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 824.295128] 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 [ 824.322563] LustreError: 26028:0:(ldlm_lib.c:1179: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. [ 824.424504] Lustre: server umount lustre-MDT0000 complete [ 835.907674] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 836.059984] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 836.417267] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 836.421852] Lustre: Skipped 1 previous similar message [ 836.472844] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 841.207339] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 841.698437] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 841.704525] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 841.733922] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 841.808974] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 841.809456] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:106 to 0x280000401:129) [ 845.448130] Lustre: *** cfs_fail_loc=1505, val=0*** [ 853.852869] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 04:25:13 (1768555513) [ 855.085535] Lustre: 26023:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 855.092299] Lustre: 26023:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 326 previous similar messages [ 855.098756] Lustre: 26023:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 855.102649] Lustre: 26023:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 326 previous similar messages [ 855.108659] Lustre: 26023:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 855.115134] Lustre: 26023:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 326 previous similar messages [ 855.119307] Lustre: 26023:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 855.122518] Lustre: 26023:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 326 previous similar messages [ 855.126699] Lustre: 26023:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 855.135742] Lustre: 26023:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 326 previous similar messages [ 855.141786] Lustre: 26023:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 855.148494] Lustre: 26023:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 326 previous similar messages [ 860.604568] Lustre: *** cfs_fail_loc=1502, val=0*** [ 871.837410] Lustre: Failing over lustre-MDT0000 [ 871.968485] LustreError: 31024:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 871.980568] LustreError: 31024:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 872.417401] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 872.424454] 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 [ 872.427729] LustreError: 26024:0:(ldlm_lib.c:1179: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. [ 872.449253] Lustre: Skipped 6 previous similar messages [ 872.478124] LustreError: 26024:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 874.146287] Lustre: server umount lustre-MDT0000 complete [ 886.699458] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 886.940973] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 887.275973] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 892.419037] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 892.432783] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 892.439478] Lustre: Skipped 3 previous similar messages [ 892.480758] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 892.520865] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:170 to 0x2c0000401:193) [ 892.524909] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 892.687766] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 896.616762] Lustre: *** cfs_fail_loc=1505, val=0*** [ 904.224527] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 04:26:04 (1768555564) [ 911.887240] Lustre: *** cfs_fail_loc=1504, val=0*** [ 911.893529] Lustre: *** cfs_fail_loc=1504, val=0*** [ 911.896881] Lustre: Skipped 1 previous similar message [ 920.392679] Lustre: Failing over lustre-MDT0000 [ 920.564473] LustreError: 32579:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 920.569544] LustreError: 32579:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 920.657210] Lustre: server umount lustre-MDT0000 complete [ 923.113516] 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 [ 923.134894] Lustre: Skipped 1 previous similar message [ 923.147087] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 932.608462] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 932.830981] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 933.125715] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 933.139685] Lustre: Skipped 1 previous similar message [ 933.200523] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 938.467201] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 938.481992] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 938.482035] Lustre: Skipped 3 previous similar messages [ 938.518207] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 938.600549] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 938.601029] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:234 to 0x2c0000401:257) [ 939.079827] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 943.249701] Lustre: *** cfs_fail_loc=1505, val=0*** [ 950.645543] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 04:26:50 (1768555610) [ 951.948098] Lustre: 27509:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 951.954585] Lustre: 27509:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 651 previous similar messages [ 951.958687] Lustre: 27509:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 951.964277] Lustre: 27509:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 652 previous similar messages [ 951.971598] Lustre: 27509:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 951.977407] Lustre: 27509:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 652 previous similar messages [ 951.982210] Lustre: 27509:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 951.986899] Lustre: 27509:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 652 previous similar messages [ 951.992146] Lustre: 27509:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 951.998491] Lustre: 27509:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 652 previous similar messages [ 952.007465] Lustre: 27509:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 952.014099] Lustre: 27509:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 652 previous similar messages [ 958.115407] Lustre: *** cfs_fail_loc=1603, val=0*** [ 967.126704] Lustre: Failing over lustre-MDT0000 [ 967.292898] LustreError: 34135:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 967.298319] LustreError: 34135:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 967.428513] Lustre: server umount lustre-MDT0000 complete [ 969.186650] 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 [ 969.191993] LustreError: 26029:0:(ldlm_lib.c:1179: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. [ 969.212682] Lustre: Skipped 5 previous similar messages [ 969.242660] LustreError: 26029:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 20 previous similar messages [ 978.778531] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 978.874980] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 979.216552] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 983.389600] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 984.549113] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 984.550620] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 984.562301] Lustre: Skipped 3 previous similar messages [ 984.601033] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 984.661179] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 984.667476] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:298 to 0x280000401:321) [ 993.761444] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 04:27:33 (1768555653) [ 1003.239229] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1013.374924] Lustre: Failing over lustre-MDT0000 [ 1013.909442] Lustre: server umount lustre-MDT0000 complete [ 1015.268231] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1015.270207] 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 [ 1015.305289] Lustre: Skipped 2 previous similar messages [ 1027.090618] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1027.184235] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1027.523425] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1031.983574] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1032.675650] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1032.689801] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1032.693745] Lustre: Skipped 3 previous similar messages [ 1032.741504] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1032.846117] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:362 to 0x280000401:385) [ 1032.848145] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 1043.511837] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 04:28:22 (1768555702) [ 1051.655904] Lustre: *** cfs_fail_loc=1605, val=0*** [ 1059.886112] Lustre: Failing over lustre-MDT0000 [ 1060.007351] LustreError: 37053:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1060.013521] LustreError: 37053:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 1060.110164] Lustre: server umount lustre-MDT0000 complete [ 1063.395717] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1071.599512] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1071.750508] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1072.064726] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1072.070255] Lustre: Skipped 2 previous similar messages [ 1072.121197] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1077.190813] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1077.226368] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1077.235841] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1077.243592] Lustre: Skipped 3 previous similar messages [ 1077.259862] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1077.317848] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:426 to 0x280000401:449) [ 1077.327701] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 1087.322116] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 04:29:07 (1768555747) [ 1088.338743] Lustre: 34005:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1088.346313] Lustre: 34005:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 980 previous similar messages [ 1088.351418] Lustre: 34005:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1088.354520] Lustre: 34005:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 980 previous similar messages [ 1088.358365] Lustre: 34005:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1088.362622] Lustre: 34005:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 980 previous similar messages [ 1088.368560] Lustre: 34005:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1088.373854] Lustre: 34005:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 979 previous similar messages [ 1088.378990] Lustre: 34005:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1088.384074] Lustre: 34005:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 980 previous similar messages [ 1088.389690] Lustre: 34005:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1088.394904] Lustre: 34005:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 980 previous similar messages [ 1093.086547] Lustre: *** cfs_fail_loc=161d, val=0*** [ 1100.998249] Lustre: Failing over lustre-MDT0000 [ 1101.257237] Lustre: server umount lustre-MDT0000 complete [ 1102.821062] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1102.829825] 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 [ 1102.834287] LustreError: 35259:0:(ldlm_lib.c:1179: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. [ 1102.856406] Lustre: Skipped 7 previous similar messages [ 1102.875314] LustreError: 35259:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 25 previous similar messages [ 1113.115674] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1113.207223] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1113.630233] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1118.691688] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1118.698417] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1118.712685] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 1118.736497] Lustre: Skipped 3 previous similar messages [ 1118.781504] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1118.845283] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:490 to 0x280000401:513) [ 1118.851469] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 1129.918403] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 04:29:49 (1768555789) [ 1133.106839] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1144.844872] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 04:30:04 (1768555804) [ 1151.222934] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1152.243603] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1163.957954] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 04:30:23 (1768555823) [ 1200.155094] Lustre: Failing over lustre-MDT0000 [ 1200.329974] LustreError: 40734:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1200.343218] LustreError: 40734:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 1200.610135] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1202.458445] Lustre: server umount lustre-MDT0000 complete [ 1208.317301] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1218.567251] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1220.899649] Lustre: 16269:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768555866/real 1768555866] req@ffff9ce5f5ce7b80 x1854464437506304/t0(0) o400->MGC192.168.202.110@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1768555882 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1220.945199] Lustre: 16269:0:(client.c:2478:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 1220.951491] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1229.405658] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1229.429716] Lustre: lustre-MDT0000: reset Object Index mappings [ 1231.351421] LustreError: 16265:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9ce4c333c380 x1854464437513088/t0(0) o250->MGC192.168.202.110@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 [ 1231.797257] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1235.713835] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1236.962286] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1236.967181] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1236.991056] Lustre: Skipped 3 previous similar messages [ 1237.018331] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1237.057226] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:593 to 0x2c0000401:609) [ 1237.057637] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:593 to 0x280000401:609) [ 1239.075576] LustreError: 42502:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 1239.096257] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1241.187727] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1241.189615] Lustre: Skipped 1 previous similar message [ 1248.449431] Lustre: Failing over lustre-MDT0000 [ 1248.624964] Lustre: server umount lustre-MDT0000 complete [ 1252.322245] 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 [ 1252.332566] Lustre: Skipped 5 previous similar messages [ 1260.057761] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1263.916866] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1265.681922] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:593 to 0x280000401:641) [ 1265.682772] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:593 to 0x2c0000401:641) [ 1266.772328] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1274.358726] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 04:32:14 (1768555934) [ 1276.468063] Lustre: *** cfs_fail_loc=1504, val=0*** [ 1284.984765] Lustre: Failing over lustre-MDT0000 [ 1285.265054] Lustre: server umount lustre-MDT0000 complete [ 1290.883222] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1301.241433] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 1301.975976] Lustre: 16269:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768555947/real 1768555947] req@ffff9ce5f0df3100 x1854464437595776/t0(0) o400->MGC192.168.202.110@tcp@0@lo:26/25 lens 224/224 e 0 to 1 dl 1768555963 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1313.363267] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1313.376094] Lustre: lustre-MDT0000: reset Object Index mappings [ 1327.592606] LustreError: 16265:0:(client.c:1390:ptlrpc_import_delay_req()) @@@ invalidate in flight req@ffff9ce5fc7fb100 x1854464437609344/t0(0) o250->MGC192.168.202.110@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 [ 1328.014761] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1328.021158] Lustre: Skipped 1 previous similar message [ 1332.644510] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1333.220597] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1333.231696] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1333.234561] Lustre: Skipped 1 previous similar message [ 1333.248842] Lustre: Skipped 7 previous similar messages [ 1333.278149] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1333.285244] Lustre: Skipped 1 previous similar message [ 1333.333209] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 1333.338212] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:682 to 0x280000401:705) [ 1336.303504] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1336.313331] Lustre: Skipped 2 previous similar messages [ 1344.548814] Lustre: *** cfs_fail_loc=1601, val=1*** [ 1344.558379] Lustre: Skipped 7 previous similar messages [ 1350.270916] Lustre: Failing over lustre-MDT0000 [ 1350.686358] Lustre: server umount lustre-MDT0000 complete [ 1361.654550] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1361.815092] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1361.826087] LustreError: Skipped 2 previous similar messages [ 1362.114106] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1362.121552] Lustre: Skipped 4 previous similar messages [ 1367.182275] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1367.591306] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:682 to 0x280000401:737) [ 1367.591696] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 1370.883945] Lustre: *** cfs_fail_loc=1505, val=0*** [ 1370.885680] Lustre: Skipped 85 previous similar messages [ 1377.896784] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 04:33:58 (1768556038) [ 1379.221914] Lustre: 27509:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1379.229528] Lustre: 27509:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 1320 previous similar messages [ 1379.233793] Lustre: 27509:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1379.243936] Lustre: 27509:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 1321 previous similar messages [ 1379.250365] Lustre: 27509:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1379.257545] Lustre: 27509:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 1321 previous similar messages [ 1379.264058] Lustre: 27509:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1379.273253] Lustre: 27509:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 1321 previous similar messages [ 1379.279760] Lustre: 27509:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1379.287744] Lustre: 27509:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 1321 previous similar messages [ 1379.296557] Lustre: 27509:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1379.305435] Lustre: 27509:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 1321 previous similar messages [ 1386.948719] Lustre: *** cfs_fail_loc=1600, val=1*** [ 1404.766913] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 04:34:24 (1768556064) [ 1419.232230] Lustre: *** cfs_fail_loc=1609, val=1*** [ 1419.235560] Lustre: Skipped 15 previous similar messages [ 1435.200678] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 04:34:54 (1768556094) [ 1452.777696] Lustre: Failing over lustre-MDT0000 [ 1453.044621] Lustre: server umount lustre-MDT0000 complete [ 1454.565799] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1454.570696] LustreError: 27509:0:(ldlm_lib.c:1179: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. [ 1454.586512] LustreError: Skipped 1 previous similar message [ 1454.617366] LustreError: 27509:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 97 previous similar messages [ 1462.623371] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1463.190754] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1463.199350] Lustre: Skipped 1 previous similar message [ 1468.251767] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1468.401918] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1468.410996] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1468.411050] Lustre: Skipped 1 previous similar message [ 1468.437435] Lustre: Skipped 7 previous similar messages [ 1468.478374] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1468.494186] Lustre: Skipped 1 previous similar message [ 1468.606420] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:855 to 0x280000401:897) [ 1468.608578] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:855 to 0x2c0000401:897) [ 1478.354392] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 04:35:38 (1768556138) [ 1495.065404] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 1516.612805] Lustre: 52430:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1544.103255] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1548.150721] Lustre: 53567:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1563.215645] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1563.218323] Lustre: Skipped 82 previous similar messages [ 1566.387181] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1567.467507] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1568.480221] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1570.528179] Lustre: *** cfs_fail_loc=1602, val=1*** [ 1570.533633] Lustre: Skipped 1 previous similar message [ 1572.300152] Lustre: Failing over lustre-MDT0000 [ 1572.445343] LustreError: 53890:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 1572.451081] LustreError: 53890:0:(obd_class.h:479:obd_check_dev()) Skipped 39 previous similar messages [ 1572.862099] Lustre: server umount lustre-MDT0000 complete [ 1575.908403] 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 [ 1575.925531] Lustre: Skipped 16 previous similar messages [ 1583.600045] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1588.738229] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1589.266110] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:947 to 0x2c0000401:993) [ 1589.269333] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:947 to 0x280000401:993) [ 1599.507288] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 04:37:39 (1768556259) [ 1604.583657] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1604.584200] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1604.603075] Lustre: Skipped 4 previous similar messages [ 1607.989239] Lustre: server umount lustre-MDT0000 complete [ 1612.564360] LustreError: 26009:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768556273 with bad export cookie 9632790624372197296 [ 1612.577545] LustreError: 26009:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1612.972521] Lustre: server umount lustre-MDT0001 complete [ 1627.777870] Lustre: server umount lustre-OST0000 complete [ 1642.046183] Lustre: server umount lustre-OST0001 complete [ 1649.565947] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [ 1657.042897] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 1705.440465] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 1717.600132] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1717.885213] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1717.911655] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1717.983837] Lustre: lustre-MDT0000: new disk, initializing [ 1718.054531] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1723.382227] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1734.532478] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1734.615414] Lustre: 58579:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 1734.642920] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 1734.648629] Lustre: Skipped 1 previous similar message [ 1734.721245] Lustre: lustre-MDT0001: new disk, initializing [ 1734.809496] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 1734.827512] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 1739.172607] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1744.040739] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 1751.478477] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1751.728725] Lustre: lustre-OST0000: new disk, initializing [ 1751.734657] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 1753.009504] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 1753.035286] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 1753.196941] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 1758.413734] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1770.015352] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1770.178733] Lustre: lustre-OST0001: new disk, initializing [ 1770.185287] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 1771.735047] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 1771.750385] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 1771.876308] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 1778.221534] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1788.860236] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1793.034548] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 1808.935352] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1809.665331] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1809.671643] Lustre: Skipped 19 previous similar messages [ 1814.120229] Lustre: *** cfs_fail_loc=1601, val=2*** [ 1814.122611] Lustre: Skipped 10 previous similar messages [ 1831.253074] Lustre: Failing over lustre-MDT0000 [ 1831.592792] Lustre: server umount lustre-MDT0000 complete [ 1842.180068] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1842.308763] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1842.313950] LustreError: Skipped 3 previous similar messages [ 1842.625358] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1842.639650] Lustre: Skipped 1 previous similar message [ 1847.699168] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1847.780102] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 1847.791658] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 1847.799654] Lustre: Skipped 1 previous similar message [ 1847.821250] Lustre: Skipped 7 previous similar messages [ 1847.863840] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 1847.879430] Lustre: Skipped 1 previous similar message [ 1847.924548] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1847.933634] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:65) [ 1847.934243] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 1856.054768] Lustre: Failing over lustre-MDT0000 [ 1856.249626] Lustre: server umount lustre-MDT0000 complete [ 1866.306598] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1871.911047] Lustre: *** cfs_fail_loc=160b, val=2*** [ 1871.925107] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:97) [ 1871.926286] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 1872.452894] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1878.990792] Lustre: Failing over lustre-MDT0000 [ 1879.272592] Lustre: server umount lustre-MDT0000 complete [ 1882.080797] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1882.086740] LustreError: Skipped 2 previous similar messages [ 1888.099864] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1888.378609] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1888.384851] Lustre: Skipped 8 previous similar messages [ 1893.316341] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1893.937606] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:129) [ 1893.938550] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:44 to 0x280000401:129) [ 1898.715814] Lustre: *** cfs_fail_loc=1602, val=2*** [ 1898.717712] Lustre: Skipped 1 previous similar message [ 1913.381693] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 04:42:52 (1768556572) [ 1927.740316] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 1948.084989] Lustre: 67922:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1972.129818] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1975.981701] Lustre: 69058:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 1991.375550] Lustre: 58587:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 1991.385879] Lustre: 58587:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 2729 previous similar messages [ 1991.394726] Lustre: 58587:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 1991.410976] Lustre: 58587:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 2729 previous similar messages [ 1991.419315] Lustre: 58587:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1991.425199] Lustre: 58587:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 2729 previous similar messages [ 1991.438505] Lustre: 58587:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1991.456172] Lustre: 58587:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 2729 previous similar messages [ 1991.466862] Lustre: 58587:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 1991.476763] Lustre: 58587:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 2729 previous similar messages [ 1991.484460] Lustre: 58587:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1991.491944] Lustre: 58587:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 2729 previous similar messages [ 2096.853456] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 04:45:56 (1768556756) [ 2149.769837] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2149.775689] Lustre: Skipped 4 previous similar messages [ 2174.677695] Lustre: *** cfs_fail_loc=160c, val=0*** [ 2174.685492] Lustre: Skipped 8 previous similar messages [ 2211.893286] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 04:47:51 (1768556871) [ 2257.748522] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2258.761102] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2258.764900] Lustre: Skipped 56 previous similar messages [ 2260.785903] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2260.793410] Lustre: Skipped 112 previous similar messages [ 2264.831402] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2264.833229] Lustre: Skipped 251 previous similar messages [ 2272.848470] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2272.853050] Lustre: Skipped 356 previous similar messages [ 2288.889940] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2288.893717] Lustre: Skipped 755 previous similar messages [ 2320.900356] Lustre: *** cfs_fail_loc=1603, val=0*** [ 2320.903241] Lustre: Skipped 1559 previous similar messages [ 2330.793342] Lustre: *** cfs_fail_loc=1604, val=0*** [ 2330.797972] Lustre: Skipped 2599 previous similar messages [ 2556.393406] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 04:53:36 (1768557216) [ 2622.008694] Lustre: 58585:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 320, rollback = 2 [ 2622.018859] Lustre: 58585:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 36839 previous similar messages [ 2622.026387] Lustre: 58585:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 1/4/0 [ 2622.035180] Lustre: 58585:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 36839 previous similar messages [ 2622.046807] Lustre: 58585:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 5/5/0, xattr_set: 7/320/0 [ 2622.055241] Lustre: 58585:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 36839 previous similar messages [ 2622.062351] Lustre: 58585:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 6/38/0, punch: 0/0/0, quota 1/3/0 [ 2622.071184] Lustre: 58585:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 36839 previous similar messages [ 2622.079860] Lustre: 58585:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 2/33/0, delete: 2/5/0 [ 2622.087115] Lustre: 58585:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 36839 previous similar messages [ 2622.095799] Lustre: 58585:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 2/2/1 [ 2622.101140] Lustre: 58585:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 36839 previous similar messages [ 2728.417837] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2728.422657] 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 [ 2728.442670] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2728.477108] Lustre: Skipped 19 previous similar messages [ 2729.402339] LustreError: 73364:0:(obd_class.h:479:obd_check_dev()) Device 22 not setup [ 2729.409310] LustreError: 73364:0:(obd_class.h:479:obd_check_dev()) Skipped 57 previous similar messages [ 2729.646502] Lustre: server umount lustre-MDT0000 complete [ 2733.438806] LustreError: 58570:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768557394 with bad export cookie 9632790624372216630 [ 2733.440369] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2733.451208] LustreError: 58570:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2733.462904] LustreError: Skipped 2 previous similar messages [ 2733.544648] LustreError: 58587:0:(ldlm_lib.c:1179: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. [ 2733.567121] LustreError: 58587:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 42 previous similar messages [ 2733.569659] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2733.585863] Lustre: Skipped 4 previous similar messages [ 2733.947490] Lustre: server umount lustre-MDT0001 complete [ 2740.635633] Lustre: server umount lustre-OST0000 complete [ 2744.620992] Lustre: server umount lustre-OST0001 complete [ 2752.263788] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 2762.278521] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2778.016438] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 2783.136538] LustreError: 74764:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.202.110@tcp: failed processing log, type 4: rc = -110 [ 2808.864479] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2815.232836] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2819.495025] Lustre: 75331:0:(ofd_dev.c:560:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2819.511602] Lustre: *** cfs_fail_loc=160e, val=3*** [ 2822.566793] Lustre: 75331:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2830.978867] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 04:58:10 (1768557490) [ 2844.697295] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 2856.148484] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2856.471669] LustreError: 74790:0:(ldlm_lib.c:1179: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. [ 2856.656702] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3273 to 0x280000401:3297) [ 2861.650607] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2872.709313] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2879.050418] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2882.712974] Lustre: 77949:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2900.280954] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2902.476658] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3233) [ 2907.524344] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2916.638803] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2921.628246] Lustre: 79432:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2931.197382] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2931.850137] Lustre: *** cfs_fail_loc=160d, val=0*** [ 2931.853512] Lustre: Skipped 3 previous similar messages [ 2937.982657] Lustre: Failing over lustre-OST0000 [ 2938.024156] LustreError: 79779:0:(obd_class.h:479:obd_check_dev()) Device 4 not setup [ 2938.035491] LustreError: 79779:0:(obd_class.h:479:obd_check_dev()) Skipped 25 previous similar messages [ 2938.087517] Lustre: server umount lustre-OST0000 complete [ 2938.343507] 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 [ 2938.370236] Lustre: Skipped 4 previous similar messages [ 2950.679926] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2950.936587] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2950.943926] Lustre: Skipped 2 previous similar messages [ 2952.615809] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2952.630767] Lustre: Skipped 2 previous similar messages [ 2952.673267] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2952.684206] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 2952.687964] Lustre: Skipped 2 previous similar messages [ 2952.693280] Lustre: *** cfs_fail_loc=215, val=0*** [ 2952.724704] Lustre: Skipped 11 previous similar messages [ 2957.792492] Lustre: *** cfs_fail_loc=215, val=0*** [ 2957.803678] Lustre: Skipped 4 previous similar messages [ 2960.060352] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2962.912853] Lustre: *** cfs_fail_loc=215, val=0*** [ 2962.912853] Lustre: *** cfs_fail_loc=215, val=0*** [ 2965.839093] Lustre: 80822:0:(ofd_dev.c:560:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 2965.970284] Lustre: 80822:0:(ofd_dev.c:572:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 2968.033312] Lustre: *** cfs_fail_loc=215, val=0*** [ 2970.518820] Lustre: Failing over lustre-OST0000 [ 2970.831777] Lustre: server umount lustre-OST0000 complete [ 2982.307449] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 2984.630292] Lustre: *** cfs_fail_loc=215, val=0*** [ 2984.644839] Lustre: Skipped 2 previous similar messages [ 2990.449275] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3001.321804] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3003.362875] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3003.383117] Lustre: Skipped 3 previous similar messages [ 3005.483500] Lustre: server umount lustre-MDT0000 complete [ 3008.491167] LustreError: 74790:0:(ldlm_lib.c:1179: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. [ 3008.513767] LustreError: 74790:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 35 previous similar messages [ 3010.636026] LustreError: 74772:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768557671 with bad export cookie 9632790624373779058 [ 3010.655149] LustreError: 74772:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3011.386860] Lustre: server umount lustre-MDT0001 complete [ 3026.090643] Lustre: server umount lustre-OST0000 complete [ 3028.960698] Lustre: 16267:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768557674/real 1768557674] req@ffff9ce5f6cd6680 x1854464441824640/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768557690 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3031.119235] Lustre: server umount lustre-OST0001 complete [ 3040.690247] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 05:01:40 (1768557700) [ 3056.455575] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 3069.024843] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3074.765889] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3085.121573] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3091.445539] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3094.741299] Lustre: 85155:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3102.238722] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3110.459277] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3113.775823] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3362 to 0x280000401:3393) [ 3120.672423] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3122.531415] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3208 to 0x2c0000401:3265) [ 3128.393546] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3136.931612] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3141.434234] Lustre: 86999:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3178.293935] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 05:03:58 (1768557838) [ 3191.815709] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 05:04:11 (1768557851) [ 3193.186504] Lustre: *** cfs_fail_loc=160f, val=0*** [ 3203.103437] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 05:04:22 (1768557862) [ 3206.865401] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3206.873912] Lustre: Skipped 3 previous similar messages [ 3259.361490] 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 [ 3259.364042] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3259.384587] Lustre: Skipped 10 previous similar messages [ 3259.396209] Lustre: Skipped 3 previous similar messages [ 3261.680452] LustreError: 89948:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 3261.688355] LustreError: 89948:0:(obd_class.h:479:obd_check_dev()) Skipped 33 previous similar messages [ 3261.838356] Lustre: server umount lustre-MDT0000 complete [ 3265.675537] LustreError: 84029:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768557926 with bad export cookie 9632790624373787500 [ 3265.697146] LustreError: 84029:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3266.121461] Lustre: server umount lustre-MDT0001 complete [ 3280.577228] Lustre: server umount lustre-OST0000 complete [ 3295.676335] Lustre: server umount lustre-OST0001 complete [ 3312.995273] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 3325.229631] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3325.657190] LustreError: 91727:0:(ldlm_lib.c:1179: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. [ 3325.679293] LustreError: 91727:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 13 previous similar messages [ 3330.180399] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3339.233408] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3344.186589] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3347.868337] Lustre: 92832:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3355.392332] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3362.066931] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3363.824060] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 3369.973215] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3554 to 0x280000401:3585) [ 3371.573942] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3373.408770] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3361) [ 3373.422881] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 3379.577843] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3388.134328] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3393.059892] Lustre: 94678:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 3405.747954] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 05:07:45 (1768558065) [ 3407.934316] Lustre: 91722:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 3407.941126] Lustre: 91722:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 1361 previous similar messages [ 3407.945480] Lustre: 91722:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 3407.949661] Lustre: 91722:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 1361 previous similar messages [ 3407.959779] Lustre: 91722:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3407.964248] Lustre: 91722:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 1361 previous similar messages [ 3407.968967] Lustre: 91722:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 3407.974658] Lustre: 91722:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 1361 previous similar messages [ 3407.979220] Lustre: 91722:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 3407.982942] Lustre: 91722:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 1361 previous similar messages [ 3407.987232] Lustre: 91722:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3407.991891] Lustre: 91722:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 1361 previous similar messages [ 3411.543632] Lustre: *** cfs_fail_loc=1610, val=0*** [ 3411.551910] Lustre: Skipped 63 previous similar messages [ 3437.025639] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 3437.036624] LustreError: Skipped 3 previous similar messages [ 3437.041208] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3440.232579] Lustre: server umount lustre-MDT0000 complete [ 3444.107027] LustreError: 92451:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768558105 with bad export cookie 9632790624373815899 [ 3444.119879] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3444.129845] LustreError: 92451:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3444.142313] LustreError: Skipped 2 previous similar messages [ 3444.461282] Lustre: server umount lustre-MDT0001 complete [ 3458.163027] Lustre: server umount lustre-OST0000 complete [ 3472.237539] Lustre: server umount lustre-OST0001 complete [ 3490.101337] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 3500.569335] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3501.113713] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3501.116626] Lustre: Skipped 13 previous similar messages [ 3506.779518] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3516.614384] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3523.866373] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3527.676226] Lustre: 98663:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 3535.325389] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3542.005031] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 3542.979425] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3546.090589] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3682 to 0x280000401:3713) [ 3552.310143] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3554.598846] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 3554.635248] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3317 to 0x2c0000401:3393) [ 3560.816723] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3570.472788] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3585.533799] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 05:10:45 (1768558245) [ 3589.351607] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3589.355896] Lustre: Skipped 63 previous similar messages [ 3589.784816] Lustre: *** cfs_fail_loc=1611, val=0*** [ 3600.300602] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 05:11:00 (1768558260) [ 3602.303074] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3602.373308] Lustre: *** cfs_fail_loc=1612, val=0*** [ 3602.376553] Lustre: Skipped 2 previous similar messages [ 3611.783586] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 05:11:11 (1768558271) [ 3613.190641] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 3614.748868] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 05:11:14 (1768558274) [ 3621.027538] Lustre: *** cfs_fail_loc=1709, val=0*** [ 3621.045172] LustreError: 97565:0:(osp_object.c:617:osp_attr_get()) lustre-MDT0000-osp-MDT0001: osp_attr_get update error [0x200003ab2:0x1:0x0]: rc = -5 [ 3621.063723] LustreError: 97565:0:(mdt_reint.c:2564:mdt_reint_migrate()) lustre-MDT0001: migrate [0x240002340:0x6c:0x0]/s12 failed: rc = -5 [ 3690.978858] 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 [ 3690.985087] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3690.993790] Lustre: Skipped 7 previous similar messages [ 3691.003424] Lustre: Skipped 7 previous similar messages [ 3693.743156] LustreError: 102145:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 3693.749985] LustreError: 102145:0:(obd_class.h:479:obd_check_dev()) Skipped 51 previous similar messages [ 3693.824978] Lustre: server umount lustre-MDT0000 complete [ 3701.469746] LustreError: 97537:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768558362 with bad export cookie 9632790624373830627 [ 3701.487382] LustreError: 97537:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3701.732414] Lustre: server umount lustre-MDT0001 complete [ 3720.502310] Lustre: server umount lustre-OST0000 complete [ 3722.720964] Lustre: 16268:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768558367/real 1768558367] req@ffff9ce5d0116a00 x1854464442825344/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768558383 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3726.896413] Lustre: 16268:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768558372/real 1768558372] req@ffff9ce4ce411f80 x1854464442825728/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768558388 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 3728.529241] Lustre: server umount lustre-OST0001 complete [ 3743.043041] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing unload_modules_local [ 3745.871781] Key type lgssc unregistered [ 3746.155447] LNet: 104329:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3746.168631] LNetError: 104329:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3746.205804] LNet: Removed LNI 192.168.202.110@tcp [ 3747.230986] Key type .llcrypt unregistered [ 3747.235733] Key type ._llcrypt unregistered [ 3774.035176] Key type ._llcrypt registered [ 3774.039585] Key type .llcrypt registered [ 3774.153331] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [ 3787.817291] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 3789.086548] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3789.104742] alg: No test for adler32 (adler32-zlib) [ 3790.229516] Lustre: Lustre: Build Version: 2.17.50_30_gc0571ea [ 3790.454253] LNet: Added LNI 192.168.202.110@tcp [8/256/0/180] [ 3792.136150] Key type lgssc registered [ 3794.131388] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3847.420783] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 3862.709865] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3862.765108] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3864.152609] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3864.194526] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3864.345766] Lustre: lustre-MDT0000: new disk, initializing [ 3864.455489] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3864.472587] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3869.710037] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3885.227160] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3885.315441] Lustre: 108724:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3885.395277] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3885.407151] Lustre: Skipped 1 previous similar message [ 3885.516996] Lustre: lustre-MDT0001: new disk, initializing [ 3885.630445] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3885.664873] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3885.671738] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3889.991338] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3895.938980] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3908.133063] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3908.450531] Lustre: lustre-OST0000: new disk, initializing [ 3908.454659] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3908.619255] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3914.789784] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3914.805439] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3914.885880] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3914.923553] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3938.669583] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 3939.051237] Lustre: lustre-OST0001: new disk, initializing [ 3939.061886] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3939.189873] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3946.593791] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3946.609558] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3946.724661] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3946.968148] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3959.479470] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3966.159370] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3978.580540] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 05:17:17 (1768558637) === [ 3988.906262] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 05:17:28 (1768558648) [ 3989.177289] Lustre: 108731:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 3989.188442] Lustre: 108731:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3989.194344] Lustre: 108731:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3989.204829] Lustre: 108731:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 3989.213522] Lustre: 108731:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 3989.228967] Lustre: 108731:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 3989.877502] Lustre: 108732:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 3989.885422] Lustre: 108732:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 9 previous similar messages [ 3989.891468] Lustre: 108732:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 3989.910484] Lustre: 108732:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3989.921441] Lustre: 108732:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3989.930095] Lustre: 108732:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3989.940914] Lustre: 108732:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 2/12/1, punch: 0/0/0, quota 7/369/2 [ 3989.956927] Lustre: 108732:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3989.963089] Lustre: 108732:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 3989.967623] Lustre: 108732:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3989.978961] Lustre: 108732:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3989.985891] Lustre: 108732:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 9 previous similar messages [ 3990.881709] Lustre: 108730:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 3990.893636] Lustre: 108730:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 116 previous similar messages [ 3990.898864] Lustre: 108730:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 3990.913222] Lustre: 108730:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3990.921502] Lustre: 108730:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 3990.933798] Lustre: 108730:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3990.946124] Lustre: 108730:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 2/12/0, punch: 0/0/0, quota 7/369/0 [ 3990.953969] Lustre: 108730:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3990.966747] Lustre: 108730:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 3990.979429] Lustre: 108730:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3990.991518] Lustre: 108730:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 3990.995644] Lustre: 108730:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 116 previous similar messages [ 3993.078413] Lustre: *** cfs_fail_loc=1613, val=0*** [ 4005.978728] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 05:17:45 (1768558665) [ 4007.307814] Lustre: 108731:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4007.315650] Lustre: 108731:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 182 previous similar messages [ 4007.320868] Lustre: 108731:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4007.328090] Lustre: 108731:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 182 previous similar messages [ 4007.336618] Lustre: 108731:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4007.343359] Lustre: 108731:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 182 previous similar messages [ 4007.351701] Lustre: 108731:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4007.357605] Lustre: 108731:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 182 previous similar messages [ 4007.363705] Lustre: 108731:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4007.369398] Lustre: 108731:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 182 previous similar messages [ 4007.376761] Lustre: 108731:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4007.385322] Lustre: 108731:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 182 previous similar messages [ 4008.619746] Lustre: *** cfs_fail_loc=1614, val=0*** [ 4013.637604] Lustre: 110620:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 4013.663807] Lustre: 110620:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 11 previous similar messages [ 4013.669928] Lustre: 110620:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 4013.685017] Lustre: 110620:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4013.693736] Lustre: 110620:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 4013.708790] Lustre: 110620:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4013.716983] Lustre: 110620:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/12/0, punch: 1/4/0, quota 7/225/0 [ 4013.723463] Lustre: 110620:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4013.739261] Lustre: 110620:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 4013.747518] Lustre: 110620:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4013.757848] Lustre: 110620:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4013.767928] Lustre: 110620:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 4020.883553] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 05:18:00 (1768558680) [ 4021.639569] Lustre: 108730:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4021.655486] Lustre: 108730:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 7 previous similar messages [ 4022.033187] Lustre: 108732:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 3/12/6, destroy: 0/0/0 [ 4022.039797] Lustre: 108732:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 10 previous similar messages [ 4022.044764] Lustre: 108732:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 3/3/0, xattr_set: 6/306/0 [ 4022.051714] Lustre: 108732:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 10 previous similar messages [ 4022.056750] Lustre: 108732:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 7/153/0, punch: 0/0/0, quota 1/3/0 [ 4022.063779] Lustre: 108732:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 10 previous similar messages [ 4022.070641] Lustre: 108732:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 7/135/3, delete: 0/0/0 [ 4022.077059] Lustre: 108732:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 10 previous similar messages [ 4022.082478] Lustre: 108732:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 4022.087858] Lustre: 108732:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 10 previous similar messages [ 4023.800722] Lustre: *** cfs_fail_loc=1615, val=0*** [ 4023.806461] Lustre: Skipped 1 previous similar message [ 4024.836429] Lustre: *** cfs_fail_loc=1615, val=0*** [ 4024.841192] Lustre: Skipped 1 previous similar message [ 4030.439756] LustreError: 113947:0:(lfsck_layout.c:2091:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x280000401:0x6d:0x0] and [0x280000401:0x6d:0x0]d: rc = 0 [ 4044.396072] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 4046.309779] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 05:18:26 (1768558706) [ 4046.826907] Lustre: 108731:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4046.838449] Lustre: 108731:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 15 previous similar messages [ 4046.845963] Lustre: 108731:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4046.852603] Lustre: 108731:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 4046.863664] Lustre: 108731:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4046.870181] Lustre: 108731:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 4046.880870] Lustre: 108731:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4046.896749] Lustre: 108731:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 4046.910124] Lustre: 108731:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4046.918865] Lustre: 108731:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 4046.926168] Lustre: 108731:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4046.934854] Lustre: 108731:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 12 previous similar messages [ 4049.104477] Lustre: *** cfs_fail_loc=1617, val=0*** [ 4049.251276] Lustre: *** cfs_fail_loc=1617, val=0*** [ 4051.873400] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4051.877267] Lustre: Skipped 3 previous similar messages [ 4074.140288] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 05:18:53 (1768558733) [ 4076.341602] Lustre: *** cfs_fail_loc=1618, val=0*** [ 4076.348132] Lustre: Skipped 5 previous similar messages [ 4110.817833] 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 [ 4110.819237] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4110.820209] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4110.844396] Lustre: Skipped 2 previous similar messages [ 4110.877096] Lustre: Skipped 3 previous similar messages [ 4115.938189] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4115.943635] Lustre: Skipped 3 previous similar messages [ 4116.175155] LustreError: 115543:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 4116.263759] Lustre: server umount lustre-MDT0000 complete [ 4120.072462] LustreError: 108716:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768558781 with bad export cookie 4734432279045690836 [ 4120.072845] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4120.082449] LustreError: 108716:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 1 previous similar message [ 4120.340726] LustreError: 115744:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 4120.345117] LustreError: 115744:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 4120.594719] Lustre: server umount lustre-MDT0001 complete [ 4135.230110] LustreError: 115946:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 4135.239245] LustreError: 115946:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 4135.283943] Lustre: server umount lustre-OST0000 complete [ 4137.440960] Lustre: 105903:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768558782/real 1768558782] req@ffff9ce4c4052300 x1854467946535808/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768558798 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4137.486536] 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 [ 4137.506983] Lustre: Skipped 1 previous similar message [ 4139.104447] LustreError: 116148:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 4139.110756] LustreError: 116148:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 4139.313534] Lustre: server umount lustre-OST0001 complete [ 4161.999922] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 4176.958340] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4177.927143] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4182.654979] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4183.010205] LustreError: 117322:0:(ldlm_lib.c:1179: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. [ 4183.030516] LustreError: 117322:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 4188.136741] LustreError: 117322:0:(ldlm_lib.c:1179: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. [ 4192.590962] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4193.005383] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 4198.184283] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4201.786244] Lustre: 118428:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4209.638508] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4209.995829] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 4216.637396] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4218.162213] LustreError: 118782:0:(ldlm_lib.c:1179: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. [ 4218.171661] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 4223.270168] LustreError: 118782:0:(ldlm_lib.c:1179: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. [ 4223.303836] LustreError: 118782:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 1 previous similar message [ 4223.308373] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 4226.583284] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4228.370943] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 4228.398261] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 4234.898841] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4243.887730] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4247.990863] Lustre: 120273:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4268.708906] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 05:22:08 (1768558928) [ 4269.195405] Lustre: 117316:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 4269.215263] Lustre: 117316:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 46 previous similar messages [ 4269.234050] Lustre: 117316:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4269.243963] Lustre: 117316:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4269.251166] Lustre: 117316:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4269.257490] Lustre: 117316:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4269.263399] Lustre: 117316:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4269.267408] Lustre: 117316:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4269.272503] Lustre: 117316:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 4269.277781] Lustre: 117316:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4269.287776] Lustre: 117316:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4269.293373] Lustre: 117316:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 46 previous similar messages [ 4271.011717] Lustre: *** cfs_fail_loc=1618, val=0*** [ 4271.013785] Lustre: Skipped 3 previous similar messages [ 4305.902948] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4305.917651] 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 [ 4305.945502] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 4307.541196] LustreError: 121048:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 4307.556786] LustreError: 121048:0:(obd_class.h:479:obd_check_dev()) Skipped 5 previous similar messages [ 4307.725072] Lustre: server umount lustre-MDT0000 complete [ 4308.982318] 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 [ 4308.987589] LustreError: 119203:0:(ldlm_lib.c:1179: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. [ 4308.993730] Lustre: Skipped 1 previous similar message [ 4309.023809] LustreError: 119203:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 3 previous similar messages [ 4312.531255] LustreError: 117303:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768558973 with bad export cookie 4734432279045706054 [ 4312.535943] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4312.560561] LustreError: 117303:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 4313.000501] Lustre: server umount lustre-MDT0001 complete [ 4328.146104] LustreError: 121450:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 4328.154951] LustreError: 121450:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 4328.220306] Lustre: server umount lustre-OST0000 complete [ 4330.464098] Lustre: 105904:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768558975/real 1768558975] req@ffff9ce5fd8d2d80 x1854467946619264/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768558991 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 4330.498272] 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 [ 4330.515217] Lustre: Skipped 1 previous similar message [ 4332.474710] Lustre: server umount lustre-OST0001 complete [ 4349.137945] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 4360.347307] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4360.779183] LustreError: 122824:0:(ldlm_lib.c:1179: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. [ 4360.921501] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4360.924175] Lustre: Skipped 1 previous similar message [ 4365.877100] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4375.737574] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4381.041737] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4384.370663] Lustre: 123928:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 4392.516545] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4400.837333] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4401.067588] LustreError: 124284:0:(ldlm_lib.c:1179: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. [ 4401.080063] LustreError: 124284:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 2 previous similar messages [ 4401.087766] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 4406.191842] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 4412.186001] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 4414.445032] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 4414.449837] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 4420.276498] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4429.892671] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 4434.281307] Lustre: 125780:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 4446.467708] Lustre: 122823:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 4446.495275] Lustre: 122823:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 21 previous similar messages [ 4446.507583] Lustre: 122823:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4446.514805] Lustre: 122823:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4446.519162] Lustre: 122823:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 4446.526924] Lustre: 122823:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4446.535503] Lustre: 122823:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/12/0, punch: 0/0/0, quota 4/150/2 [ 4446.544977] Lustre: 122823:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4446.562269] Lustre: 122823:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 4446.572323] Lustre: 122823:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4446.578850] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4446.582603] Lustre: 122823:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4446.599453] Lustre: 122823:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 4475.363201] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 05:25:35 (1768559135) [ 4478.840307] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4478.845706] Lustre: Skipped 3 previous similar messages [ 4486.070687] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4511.918240] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 05:26:10 (1768559170) [ 4515.348970] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4515.355068] Lustre: *** cfs_fail_loc=162e, val=0*** [ 4515.361126] Lustre: Skipped 7 previous similar messages [ 4534.150709] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 05:26:34 (1768559194) [ 4542.004898] LustreError: 128773:0:(lfsck_layout.c:2091:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x2c0000401:0x44:0x0] and [0x2c0000401:0x44:0x0]d: rc = 0 [ 4558.936600] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 05:26:58 (1768559218) [ 4572.587174] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 05:27:11 (1768559231) [ 4576.657473] Lustre: 122820:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 4576.679270] Lustre: 122820:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 97 previous similar messages [ 4576.697319] Lustre: 122820:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 4576.714213] Lustre: 122820:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 97 previous similar messages [ 4576.723841] Lustre: 122820:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4576.741582] Lustre: 122820:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 97 previous similar messages [ 4576.756234] Lustre: 122820:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 2/12/1, punch: 0/0/0, quota 1/3/2 [ 4576.769750] Lustre: 122820:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 97 previous similar messages [ 4576.781114] Lustre: 122820:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 4576.788838] Lustre: 122820:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 97 previous similar messages [ 4576.805975] Lustre: 122820:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 4576.829278] Lustre: 122820:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 97 previous similar messages [ 4577.071617] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4577.116061] Lustre: *** cfs_fail_loc=1611, val=0*** [ 4577.117792] Lustre: Skipped 3 previous similar messages [ 4584.294814] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.10@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 4585.457720] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.202.10@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 4594.598402] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 05:27:34 (1768559254) [ 4596.878621] Lustre: *** cfs_fail_loc=1616, val=0*** [ 4596.882068] Lustre: Skipped 3 previous similar messages [ 4625.370590] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 05:28:04 (1768559284) [ 4637.441344] LustreError: 130987:0:(lfsck_layout.c:2091:lfsck_layout_add_comp()) five: Five five five five five five file Hello [0x280000401:0xd3:0x0] and [0x280000401:0xd3:0x0]d: rc = 0 [ 4661.784569] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 05:28:41 (1768559321) [ 4676.544753] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 05:28:56 (1768559336) [ 4679.047060] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4679.060681] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4679.063590] Lustre: Skipped 1 previous similar message [ 4692.036199] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 05:29:11 (1768559351) [ 4693.940931] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4693.952627] Lustre: *** cfs_fail_loc=161e, val=0*** [ 4705.530028] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 05:29:25 (1768559365) [ 4707.431609] Lustre: *** cfs_fail_loc=1620, val=0*** [ 4722.987895] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 4724.937361] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 05:29:44 (1768559384) [ 4731.886041] Lustre: *** cfs_fail_loc=1621, val=140*** [ 4731.889736] Lustre: Skipped 1 previous similar message [ 4735.292796] Lustre: *** cfs_fail_loc=1602, val=10*** [ 4756.244211] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 05:30:15 (1768559415) [ 4758.531735] Lustre: Failing over lustre-MDT0000 [ 4758.636367] Lustre: lustre-MDT0000: Not available for connect from 192.168.202.10@tcp (stopping) [ 4758.879259] LustreError: 134412:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 4758.888268] LustreError: 134412:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [ 4758.991214] Lustre: server umount lustre-MDT0000 complete [ 4760.039977] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 4760.063520] 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 [ 4760.099955] LustreError: 126043:0:(ldlm_lib.c:1179: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. [ 4760.133244] LustreError: 126043:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 4 previous similar messages [ 4769.275465] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 4769.352347] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4769.625742] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4769.628763] Lustre: Skipped 3 previous similar messages [ 4769.672879] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4772.399174] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 4774.900882] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4774.956290] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 4775.035932] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:271 to 0x280000401:289) [ 4775.038560] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:137 to 0x2c0000401:161) [ 4775.070419] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 4777.261733] LustreError: 125583:0:(mdt_open.c:1326:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x8f:0x0] doesn't exist!: rc = -14 [ 4789.500456] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 05:30:49 (1768559449) [ 4791.369944] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4791.587553] Lustre: *** cfs_fail_loc=1622, val=0*** [ 4791.591400] Lustre: Skipped 1 previous similar message [ 4803.416857] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 05:31:03 (1768559463) [ 4805.302555] Lustre: *** cfs_fail_loc=1623, val=0*** [ 4816.794533] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 05:31:16 (1768559476) [ 4818.680598] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4829.230433] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 05:31:28 (1768559488) [ 4842.433605] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 05:31:41 (1768559501) [ 4843.017797] Lustre: 125583:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 4843.027924] Lustre: 125583:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 514 previous similar messages [ 4843.033303] Lustre: 125583:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 4843.039778] Lustre: 125583:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 514 previous similar messages [ 4843.045338] Lustre: 125583:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 4843.051858] Lustre: 125583:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 514 previous similar messages [ 4843.064793] Lustre: 125583:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 4843.069672] Lustre: 125583:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 514 previous similar messages [ 4843.080196] Lustre: 125583:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 4843.090355] Lustre: 125583:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 514 previous similar messages [ 4843.097231] Lustre: 125583:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 4843.107019] Lustre: 125583:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 514 previous similar messages [ 4844.390373] Lustre: *** cfs_fail_loc=1624, val=0*** [ 4844.393201] Lustre: Skipped 1 previous similar message [ 4856.013713] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 05:31:55 (1768559515) [ 4869.115407] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 05:32:09 (1768559529) [ 4875.328853] Lustre: *** cfs_fail_loc=161c, val=0*** [ 4875.330677] Lustre: Skipped 1 previous similar message [ 4891.071293] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 05:32:30 (1768559550) [ 4893.539531] Lustre: *** cfs_fail_loc=1626, val=0*** [ 4893.542181] Lustre: Skipped 4 previous similar messages [ 4903.954408] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 05:32:43 (1768559563) [ 4937.562894] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 05:33:17 (1768559597) [ 4940.397608] LustreError: 125583:0:(osd_handler.c:287:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0xab:0x0]: rc = -2 [ 4947.466819] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 05:33:27 (1768559607) [ 4972.185424] Lustre: Failing over lustre-MDT0000 [ 4972.469277] LustreError: 140877:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 4972.477074] LustreError: 140877:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 4972.521512] 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 [ 4972.536060] Lustre: Skipped 3 previous similar messages [ 4972.558417] LustreError: 122823:0:(ldlm_lib.c:1179: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. [ 4972.573698] LustreError: 122823:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 11 previous similar messages [ 4972.832762] Lustre: server umount lustre-MDT0000 complete [ 4985.110319] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 4985.210256] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 4985.431495] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 4985.505705] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 4990.436434] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 4990.447851] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 4990.469467] Lustre: Skipped 3 previous similar messages [ 4990.486740] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 4990.531082] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 4990.533310] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 4990.933772] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5006.262445] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 05:34:25 (1768559665) [ 5021.230619] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 05:34:40 (1768559680) [ 5036.268399] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 05:34:55 (1768559695) [ 5037.715824] Lustre: *** cfs_fail_loc=1629, val=0*** [ 5037.717959] Lustre: Skipped 15 previous similar messages [ 5052.781125] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 05:35:12 (1768559712) [ 5060.408792] Lustre: Failing over lustre-MDT0000 [ 5060.603751] LustreError: 143480:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 5060.608080] LustreError: 143480:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 5060.875622] Lustre: server umount lustre-MDT0000 complete [ 5062.113575] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5062.121743] 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 [ 5062.148988] Lustre: Skipped 5 previous similar messages [ 5071.952400] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5072.113933] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5072.394937] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5077.317862] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5077.477760] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5077.494667] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 5077.500694] Lustre: Skipped 3 previous similar messages [ 5077.549599] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5077.588624] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 5077.593786] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 5088.357214] Lustre: Failing over lustre-MDT0000 [ 5088.737472] Lustre: server umount lustre-MDT0000 complete [ 5092.836968] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5098.359643] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5098.486641] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5098.719554] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5100.598336] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5104.131446] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 5104.149333] Lustre: Skipped 3 previous similar messages [ 5104.211767] Lustre: lustre-MDT0000: Recovery over after 0:04, of 2 clients 2 recovered and 0 were evicted. [ 5104.277684] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:385) [ 5104.280557] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:227 to 0x2c0000401:257) [ 5104.281909] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5116.744550] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 05:36:16 (1768559776) [ 5130.297201] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 05:36:30 (1768559790) [ 5145.451448] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 05:36:44 (1768559804) [ 5186.326876] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 05:37:26 (1768559846) [ 5201.342339] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 05:37:40 (1768559860) [ 5211.464171] LustreError: 147579:0:(lfsck_layout.c:4468:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5214.413291] Lustre: Failing over lustre-OST0000 [ 5214.487391] LustreError: 147729:0:(obd_class.h:479:obd_check_dev()) Device 23 not setup [ 5214.493648] LustreError: 147729:0:(obd_class.h:479:obd_check_dev()) Skipped 15 previous similar messages [ 5214.539948] LustreError: 147579:0:(lfsck_layout.c:4468:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d awake [ 5214.551373] LustreError: 147579:0:(lfsck_layout.c:4468:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5214.591538] Lustre: server umount lustre-OST0000 complete [ 5215.203182] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 5215.213555] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5215.229023] Lustre: Skipped 5 previous similar messages [ 5215.241311] LustreError: 124285:0:(ldlm_lib.c:1179: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. [ 5215.257131] LustreError: 124285:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 27 previous similar messages [ 5217.628915] LustreError: 147579:0:(lfsck_layout.c:4468:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 5230.989370] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5231.355717] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 5232.682123] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5232.719332] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 5232.719378] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 5232.736198] Lustre: Skipped 3 previous similar messages [ 5239.106781] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5250.827820] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 05:38:30 (1768559910) [ 5269.475580] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 5291.868700] Lustre: 150355:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5318.318300] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5322.123802] Lustre: 151491:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5339.665318] LustreError: 151629:0:(lfsck_striped_dir.c:1755:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5342.145842] Lustre: Failing over lustre-MDT0001 [ 5342.672162] LustreError: 151629:0:(lfsck_striped_dir.c:1755:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 5342.777281] LustreError: 151628:0:(lfsck_striped_dir.c:1755:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 5342.781310] LustreError: lustre-MDT0001-osp-MDT0000: operation out_update to node 0@lo failed: rc = -107 [ 5342.807987] LustreError: 151628:0:(lfsck_striped_dir.c:1755:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 5342.842164] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 5343.003085] Lustre: server umount lustre-MDT0001 complete [ 5344.232390] Lustre: lustre-MDT0001-lwp-OST0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 5344.238137] Lustre: Skipped 2 previous similar messages [ 5345.795283] LustreError: 151628:0:(lfsck_striped_dir.c:1755:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 5345.806882] LustreError: 151628:0:(lfsck_striped_dir.c:1755:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 5359.618295] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5360.150817] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 5360.164468] Lustre: Skipped 3 previous similar messages [ 5360.228778] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5365.234873] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 5365.243087] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 5365.259523] Lustre: Skipped 1 previous similar message [ 5365.300934] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 5365.409848] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 5365.421729] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 5365.948974] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5376.679260] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 05:40:36 (1768560036) [ 5393.645278] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 5414.903697] Lustre: 154315:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5439.697593] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5443.311523] Lustre: 155449:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5450.810418] Lustre: 151072:0:(osd_internal.h:1459:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 5450.822124] Lustre: 151072:0:(osd_internal.h:1459:osd_trans_exec_op()) Skipped 1270 previous similar messages [ 5450.833074] Lustre: 151072:0:(osd_handler.c:2096:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 5450.837436] Lustre: 151072:0:(osd_handler.c:2096:osd_trans_dump_creds()) Skipped 1270 previous similar messages [ 5450.841429] Lustre: 151072:0:(osd_handler.c:2103:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 5450.846120] Lustre: 151072:0:(osd_handler.c:2103:osd_trans_dump_creds()) Skipped 1270 previous similar messages [ 5450.857879] Lustre: 151072:0:(osd_handler.c:2113:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 5450.864660] Lustre: 151072:0:(osd_handler.c:2113:osd_trans_dump_creds()) Skipped 1270 previous similar messages [ 5450.869215] Lustre: 151072:0:(osd_handler.c:2120:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 5450.872945] Lustre: 151072:0:(osd_handler.c:2120:osd_trans_dump_creds()) Skipped 1270 previous similar messages [ 5450.877834] Lustre: 151072:0:(osd_handler.c:2127:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 5450.883359] Lustre: 151072:0:(osd_handler.c:2127:osd_trans_dump_creds()) Skipped 1270 previous similar messages [ 5472.326366] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 05:42:11 (1768560131) [ 5474.109751] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 5476.400517] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 05:42:16 (1768560136) [ 5484.563959] Lustre: *** cfs_fail_loc=1631, val=0*** [ 5498.341487] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 5498.341918] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 5498.350587] Lustre: Skipped 2 previous similar messages [ 5504.213487] LustreError: 156432:0:(obd_class.h:479:obd_check_dev()) Device 10 not setup [ 5504.220049] LustreError: 156432:0:(obd_class.h:479:obd_check_dev()) Skipped 11 previous similar messages [ 5504.561305] Lustre: server umount lustre-MDT0000 complete [ 5508.604259] LustreError: 122819:0:(ldlm_lib.c:1179: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. [ 5508.609606] LustreError: 139887:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768560169 with bad export cookie 4734432279045782991 [ 5508.622711] LustreError: 122819:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 21 previous similar messages [ 5508.631620] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5508.644829] LustreError: 139887:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 2 previous similar messages [ 5509.049113] Lustre: server umount lustre-MDT0001 complete [ 5523.061693] Lustre: server umount lustre-OST0000 complete [ 5537.290732] Lustre: server umount lustre-OST0001 complete [ 5553.307548] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 5564.721636] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5570.038733] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5580.821500] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5586.447141] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5589.769603] Lustre: 159317:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 5598.164330] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5605.770546] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5606.637656] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 5610.739372] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:542 to 0x280000401:577) [ 5615.898973] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5617.328636] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 5617.363196] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:414 to 0x2c0000401:449) [ 5622.806949] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5629.416857] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 5632.530631] Lustre: 161159:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 5648.190684] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 05:45:07 (1768560307) [ 5649.756877] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 5651.880762] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 05:45:11 (1768560311) [ 5653.466456] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 5655.297597] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 05:45:15 (1768560315) [ 5656.868000] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 5658.339572] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 05:45:18 (1768560318) [ 5666.726873] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 05:45:26 (1768560326) [ 5679.128892] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 05:45:38 (1768560338) [ 5695.433121] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 05:45:55 (1768560355) [ 5713.166288] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 05:46:12 (1768560372) [ 5734.564565] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 05:46:34 (1768560394) [ 5768.302863] Lustre: *** cfs_fail_loc=1632, val=0*** [ 5783.294098] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 05:47:22 (1768560442) [ 5785.774970] Lustre: Failing over lustre-MDT0001 [ 5786.002535] Lustre: server umount lustre-MDT0001 complete [ 5786.086293] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 5786.090481] 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 [ 5786.096904] Lustre: Skipped 5 previous similar messages [ 5793.943105] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5794.453838] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 5794.457634] Lustre: lustre-MDT0001: Aborting client recovery [ 5794.463041] LustreError: 164952:0:(ldlm_lib.c:2984:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 5794.467453] LustreError: 164979:0:(lod_dev.c:510:lod_sub_recovery_thread()) lustre-MDT0000-osp-MDT0001: get update log duration 0, retries 0, failed: rc = -108 [ 5794.472875] Lustre: 164980:0:(ldlm_lib.c:2387:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 5794.486599] Lustre: 164980:0:(genops.c:1618:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 798349ab-40c5-41a9-8ae2-a7531f75b757@ [ 5794.492767] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 5794.499730] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 5794.511530] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 5794.575408] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:131 to 0x2c0000400:161) [ 5794.575754] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:161) [ 5798.569680] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5799.910791] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5799.927111] Lustre: Skipped 2 previous similar messages [ 5799.933110] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 5806.484322] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 5806.751764] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 0 sec [ 5813.109236] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 05:47:52 (1768560472) [ 5823.226057] Lustre: *** cfs_fail_loc=1600, val=3*** [ 5826.297393] Lustre: Failing over lustre-MDT0000 [ 5826.658590] Lustre: server umount lustre-MDT0000 complete [ 5838.248724] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 5838.443777] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5838.790704] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 5838.802195] Lustre: Skipped 2 previous similar messages [ 5841.460821] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 5843.369410] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5843.949352] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 5843.959696] Lustre: Skipped 2 previous similar messages [ 5843.984855] Lustre: lustre-MDT0000: Recovery over after 0:02, of 2 clients 2 recovered and 0 were evicted. [ 5844.039796] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:622 to 0x280000401:641) [ 5844.039796] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 5854.447287] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 05:48:34 (1768560514) [ 5879.775323] Lustre: Failing over lustre-OST0000 [ 5879.808085] Lustre: lustre-OST0000: Not available for connect from 0@lo (stopping) [ 5879.812805] Lustre: Skipped 5 previous similar messages [ 5880.074369] Lustre: server umount lustre-OST0000 complete [ 5888.560117] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 5904.249320] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 5904.455172] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 5904.460286] Lustre: Skipped 6 previous similar messages [ 5904.486220] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 5905.955358] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 5906.079504] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 5912.179759] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 5919.530308] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 5919.744815] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 5924.508504] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing wait_import_state FULL os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 5924.803629] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 5930.525221] Lustre: DEBUG MARKER: oleg210-client.virtnet: executing wait_import_state FULL osc.lustre-OST0000-osc-ffff8fe973aea000.ost_server_uuid 50 [ 5932.546454] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffff8fe973aea000.ost_server_uuid in FULL state after 0 sec [ 5975.368445] Lustre: server umount lustre-MDT0000 complete [ 5983.095659] LustreError: 161872:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768560644 with bad export cookie 4734432279045866613 [ 5983.098775] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 5983.109783] LustreError: 161872:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 5983.527392] Lustre: server umount lustre-MDT0001 complete [ 6002.656202] Lustre: 105903:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560647/real 1768560647] req@ffff9ce4c32ab480 x1854467948464384/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560663 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6003.764308] Lustre: server umount lustre-OST0000 complete [ 6004.707525] Lustre: 105905:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560649/real 1768560649] req@ffff9ce4c322fb80 x1854467948464768/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560665 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6007.713615] Lustre: 105902:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560652/real 1768560652] req@ffff9ce4c322e300 x1854467948465024/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560668 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6009.836880] Lustre: 105904:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560655/real 1768560655] req@ffff9ce4c32aad80 x1854467948465536/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560671 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6011.811092] Lustre: server umount lustre-OST0001 complete [ 6030.609618] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing unload_modules_local [ 6034.016993] Key type lgssc unregistered [ 6034.418735] LNet: 173254:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6034.422325] LNetError: 173254:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6035.495605] LNet: Removed LNI 192.168.202.110@tcp [ 6036.552145] Key type .llcrypt unregistered [ 6036.555924] Key type ._llcrypt unregistered [ 6065.936970] Key type ._llcrypt registered [ 6065.943461] Key type .llcrypt registered [ 6066.110429] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_hostid [ 6084.631313] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 6085.773663] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 6085.802881] alg: No test for adler32 (adler32-zlib) [ 6087.032404] Lustre: Lustre: Build Version: 2.17.50_30_gc0571ea [ 6087.231346] LNet: Added LNI 192.168.202.110@tcp [8/256/0/180] [ 6088.904177] Key type lgssc registered [ 6089.808688] Lustre: Echo OBD driver; http://www.lustre.org/ [ 6143.066366] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing load_modules_local [ 6156.814620] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 6156.846039] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 6158.148904] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 6158.174955] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 6158.261321] Lustre: lustre-MDT0000: new disk, initializing [ 6158.365356] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 6158.381919] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 6163.809467] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6179.510464] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6179.597408] Lustre: 177655:0:(mgs_llog.c:1348:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 6179.630378] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 6179.634742] Lustre: Skipped 1 previous similar message [ 6179.702881] Lustre: lustre-MDT0001: new disk, initializing [ 6179.768730] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 6179.803062] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 6179.814299] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 6184.475272] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6189.041630] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 6197.031761] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6197.263179] Lustre: lustre-OST0000: new disk, initializing [ 6197.269238] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 6197.330701] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 6202.288387] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6202.904276] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 6202.911901] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 6203.007200] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 6215.656864] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 6215.847468] Lustre: lustre-OST0001: new disk, initializing [ 6215.854113] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 6215.921546] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 6222.232558] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 6222.898657] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 6222.915456] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 6223.005088] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 6234.306809] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 6241.365538] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 6252.944837] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 05:55:12 (1768560912) === [ 6254.930798] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 5953 sec ========= 05:55:14 (1768560914) [ 6257.312242] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 05:55:16 (1768560916) === [ 6262.317528] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 05:55:21 (1768560921) === [ 6266.850845] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 6266.862857] 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 [ 6266.887506] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6268.921127] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 6268.922484] 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 [ 6268.933941] Lustre: Skipped 2 previous similar messages [ 6268.968979] Lustre: Skipped 2 previous similar messages [ 6273.044057] LustreError: 181817:0:(obd_class.h:479:obd_check_dev()) Device 28 not setup [ 6273.246740] Lustre: server umount lustre-MDT0000 complete [ 6279.143502] LustreError: 177665:0:(ldlm_lib.c:1179: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. [ 6279.151905] LustreError: 177665:0:(ldlm_lib.c:1179:target_handle_connect()) Skipped 8 previous similar messages [ 6282.012928] LustreError: 177646:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1768560943 with bad export cookie 3062104535763924275 [ 6282.017249] LustreError: MGC192.168.202.110@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 6282.018269] LustreError: 177646:0:(ldlm_lockd.c:2563:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 6282.114849] LustreError: 182269:0:(obd_class.h:479:obd_check_dev()) Device 27 not setup [ 6282.121454] LustreError: 182269:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 6282.252461] Lustre: server umount lustre-MDT0001 complete [ 6300.111416] LustreError: 182719:0:(obd_class.h:479:obd_check_dev()) Device 19 not setup [ 6300.119266] LustreError: 182719:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [ 6300.209739] Lustre: server umount lustre-OST0000 complete [ 6300.644517] Lustre: 174834:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560945/real 1768560945] req@ffff9ce5c7ab7b80 x1854470354981248/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560961 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6300.697839] 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 [ 6303.463025] Lustre: 174835:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560948/real 1768560948] req@ffff9ce4ce12f480 x1854470354981504/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560964 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6305.760303] Lustre: 174833:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560950/real 1768560950] req@ffff9ce601e0aa00 x1854470354981760/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560966 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6308.321820] Lustre: 174836:0:(client.c:2478:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1768560953/real 1768560953] req@ffff9ce5ed9cea00 x1854470354982144/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1768560969 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 6312.448161] LustreError: 183172:0:(obd_class.h:479:obd_check_dev()) Device 2 not setup [ 6312.454771] LustreError: 183172:0:(obd_class.h:479:obd_check_dev()) Skipped 3 previous similar messages [ 6312.650994] Lustre: server umount lustre-OST0001 complete [ 6330.462414] Lustre: DEBUG MARKER: oleg210-server.virtnet: executing unload_modules_local [ 6333.959855] Key type lgssc unregistered [ 6334.294787] LNet: 184003:0:(lib-ptl.c:967:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 6334.306808] LNetError: 184003:0:(acceptor.c:264:lnet_acceptor_remove_socket()) Interface ens2 not found [ 6334.324226] LNet: Removed LNI 192.168.202.110@tcp [ 6335.250180] Key type .llcrypt unregistered [ 6335.254371] Key type ._llcrypt unregistered