[ 0.000000] Linux version 4.18.0rh8.10-debug (green@maintenance) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-26) (GCC)) #2 SMP Mon Jul 14 01:24:22 EDT 2025 [ 0.000000] Command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] signal: max sigframe size: 1776 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffcdfff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffce000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000146dfffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.17.0-10.fc44 06/10/2025 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000000] kvm-clock: using sched offset of 446955937 cycles [ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000000] tsc: Detected 2399.998 MHz processor [ 0.000000] last_pfn = 0x146e00 max_arch_pfn = 0x400000000 [ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.000000] last_pfn = 0xbffce max_arch_pfn = 0x400000000 [ 0.000000] found SMP MP-table at [mem 0x000f54b0-0x000f54bf] [ 0.000000] RAMDISK: [mem 0xbcc54000-0xbffbffff] [ 0.000000] ACPI: Early table checksum verification disabled [ 0.000000] ACPI: RSDP 0x00000000000F52D0 000014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 0x00000000BFFE247C 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 0x00000000BFFE2318 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 0x00000000BFFE0040 0022D8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 0x00000000BFFE0000 000040 [ 0.000000] ACPI: APIC 0x00000000BFFE238C 000090 (v03 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: HPET 0x00000000BFFE241C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 0x00000000BFFE2454 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: Reserving FACP table memory at [mem 0xbffe2318-0xbffe238b] [ 0.000000] ACPI: Reserving DSDT table memory at [mem 0xbffe0040-0xbffe2317] [ 0.000000] ACPI: Reserving FACS table memory at [mem 0xbffe0000-0xbffe003f] [ 0.000000] ACPI: Reserving APIC table memory at [mem 0xbffe238c-0xbffe241b] [ 0.000000] ACPI: Reserving HPET table memory at [mem 0xbffe241c-0xbffe2453] [ 0.000000] ACPI: Reserving WAET table memory at [mem 0xbffe2454-0xbffe247b] [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at [mem 0x0000000000000000-0x0000000146dfffff] [ 0.000000] NODE_DATA(0) allocated [mem 0x1465a3000-0x1465cdfff] [ 0.000000] Reserving 256MB of memory at 2752MB for crashkernel (System RAM: 4205MB) [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.000000] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Device empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.000000] node 0: [mem 0x0000000000100000-0x00000000bffcdfff] [ 0.000000] node 0: [mem 0x0000000100000000-0x0000000146dfffff] [ 0.000000] Zeroed struct page in unavailable ranges: 4756 pages [ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x0000000146dfffff] [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.000000] TSC deadline timer available [ 0.000000] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.000000] kvm-guest: KVM setup pv remote TLB flush [ 0.000000] kvm-guest: setup PV sched yield [ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.000000] PM: Registered nosave memory: [mem 0xbffce000-0xbfffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.000000] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.000000] Booting paravirtualized kernel on KVM [ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns [ 0.000000] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.000000] percpu: Embedded 63 pages/cpu s221184 r8192 d28672 u524288 [ 0.000000] kvm-guest: PV spinlocks enabled [ 0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1059606 [ 0.000000] Policy zone: Normal [ 0.000000] Kernel command line: rd.shell root=nbd:192.168.200.253:rocky8.10:ext4:ro:-p,-b4096 ro crashkernel=256M panic=1 nomodeset ipmtu=9000 ip=dhcp rd.neednet=1 init_on_free=off mitigations=off console=ttyS1,115200 audit=0 [ 0.000000] Specific versions of hardware are certified with Red Hat Enterprise Linux 8. Please see the list of hardware certified with Red Hat Enterprise Linux 8 at https://catalog.redhat.com. [ 0.000000] audit: disabled (until reboot) [ 0.000000] software IO TLB: area num 4. [ 0.000000] Memory: 2829652K/4306352K available (18435K kernel code, 11221K rwdata, 7248K rodata, 2908K init, 18040K bss, 524584K reserved, 0K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] ftrace: allocating 41240 entries in 162 pages [ 0.000000] ftrace: allocated 162 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x622/0x9a8 with crng_init=0 [ 0.001000] Console: colour *CGA 80x25 [ 0.001000] printk: console [ttyS1] enabled [ 0.001000] ACPI: Core revision 20220331 [ 0.001000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.001010] APIC: Switch to symmetric I/O mode setup [ 0.002233] x2apic enabled [ 0.003007] Switched APIC routing to physical x2apic. [ 0.004008] kvm-guest: setup PV IPIs [ 0.006845] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.007000] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 0.007019] Calibrating delay loop (skipped) preset value.. 4799.99 BogoMIPS (lpj=2399998) [ 0.008010] pid_max: default: 32768 minimum: 301 [ 0.009115] LSM: Security Framework initializing [ 0.010073] Yama: becoming mindful. [ 0.011024] SELinux: Initializing. [ 0.012067] *** VALIDATE selinux *** [ 0.020277] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc) [ 0.024555] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc) [ 0.025138] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.027004] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc) [ 0.028120] *** VALIDATE tmpfs *** [ 0.030290] *** VALIDATE proc *** [ 0.031216] *** VALIDATE cgroup *** [ 0.032007] *** VALIDATE cgroup2 *** [ 0.033207] x86/cpu: User Mode Instruction Prevention (UMIP) activated [ 0.035115] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.036008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.037028] Spectre V2 : User space: Vulnerable [ 0.038007] Speculative Store Bypass: Vulnerable [ 0.041200] debug: unmapping init [mem 0xffffffffaf059000-0xffffffffaf060fff] [ 0.043821] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz (family: 0x6, model: 0x3e, stepping: 0x4) [ 0.044431] Performance Events: IvyBridge events, full-width counters, Intel PMU driver. [ 0.045015] ... version: 2 [ 0.045985] ... bit width: 48 [ 0.046014] ... generic registers: 4 [ 0.047009] ... value mask: 0000ffffffffffff [ 0.048010] ... max period: 00007fffffffffff [ 0.049012] ... fixed-purpose events: 3 [ 0.050011] ... event mask: 000000070000000f [ 0.051293] rcu: Hierarchical SRCU implementation. [ 0.053284] smp: Bringing up secondary CPUs ... [ 0.054436] x86: Booting SMP configuration: [ 0.055019] .... node #0, CPUs: #1 #2 #3 [ 0.060191] smp: Brought up 1 node, 4 CPUs [ 0.062020] smpboot: Max logical packages: 1 [ 0.063016] smpboot: Total of 4 processors activated (19199.98 BogoMIPS) [ 0.222329] node 0 deferred pages initialised in 154ms [ 0.225418] devtmpfs: initialized [ 0.226266] x86/mm: Memory block size: 128MB [ 0.229046] gcov: version magic: 0x41383552 [ 0.231300] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns [ 0.232102] futex hash table entries: 1024 (order: 4, 65536 bytes, vmalloc) [ 0.233255] pinctrl core: initialized pinctrl subsystem [ 0.234232] [ 0.234818] ************************************************************* [ 0.235018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.236014] ** ** [ 0.237017] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 0.238012] ** ** [ 0.239013] ** This means that this kernel is built to expose internal ** [ 0.240013] ** IOMMU data structures, which may compromise security on ** [ 0.241016] ** your system. ** [ 0.242019] ** ** [ 0.243018] ** If you see this message and you are not debugging the ** [ 0.244017] ** kernel, report this immediately to your vendor! ** [ 0.245019] ** ** [ 0.246018] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 0.247016] ************************************************************* [ 0.248844] NET: Registered protocol family 16 [ 0.249579] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations [ 0.250082] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.251081] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.252544] cpuidle: using governor menu [ 0.255038] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.258807] PCI: Using configuration type 1 for base access [ 0.261115] core: PMU erratum BJ122, BV98, HSD29 worked around, HT is on [ 0.270072] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages [ 0.271022] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.273036] cryptd: max_cpu_qlen set to 1000 [ 0.276367] ACPI: Added _OSI(Module Device) [ 0.277015] ACPI: Added _OSI(Processor Device) [ 0.278014] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.279022] ACPI: Added _OSI(Processor Aggregator Device) [ 0.283843] ACPI: 1 ACPI AML tables successfully acquired and loaded [ 0.292225] ACPI: Interpreter enabled [ 0.293045] ACPI: PM: (supports S0 S3 S4 S5) [ 0.294010] ACPI: Using IOAPIC for interrupt routing [ 0.296087] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.300478] ACPI: Enabled 2 GPEs in block 00 to 0F [ 0.310978] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.313030] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.316021] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] [ 0.321131] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.327958] acpiphp: Slot [2] registered [ 0.330220] acpiphp: Slot [5] registered [ 0.332208] acpiphp: Slot [6] registered [ 0.334196] acpiphp: Slot [7] registered [ 0.336137] acpiphp: Slot [8] registered [ 0.338190] acpiphp: Slot [9] registered [ 0.340266] acpiphp: Slot [10] registered [ 0.341170] acpiphp: Slot [3] registered [ 0.343143] acpiphp: Slot [4] registered [ 0.344147] acpiphp: Slot [11] registered [ 0.345120] acpiphp: Slot [12] registered [ 0.346115] acpiphp: Slot [13] registered [ 0.348100] acpiphp: Slot [14] registered [ 0.349173] acpiphp: Slot [15] registered [ 0.350102] acpiphp: Slot [16] registered [ 0.352071] acpiphp: Slot [17] registered [ 0.353077] acpiphp: Slot [18] registered [ 0.354073] acpiphp: Slot [19] registered [ 0.355071] acpiphp: Slot [20] registered [ 0.356074] acpiphp: Slot [21] registered [ 0.357106] acpiphp: Slot [22] registered [ 0.359099] acpiphp: Slot [23] registered [ 0.360070] acpiphp: Slot [24] registered [ 0.361073] acpiphp: Slot [25] registered [ 0.362076] acpiphp: Slot [26] registered [ 0.364081] acpiphp: Slot [27] registered [ 0.365082] acpiphp: Slot [28] registered [ 0.366089] acpiphp: Slot [29] registered [ 0.368122] acpiphp: Slot [30] registered [ 0.369090] acpiphp: Slot [31] registered [ 0.370048] PCI host bridge to bus 0000:00 [ 0.371015] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.373016] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.375023] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.377020] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.379016] pci_bus 0000:00: root bus resource [mem 0xe0000000000-0xe007fffffff window] [ 0.381022] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.383160] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.385496] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.389372] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.400938] pci 0000:00:01.1: reg 0x20: [io 0xc320-0xc32f] [ 0.407106] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.410024] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.412012] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.413011] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.416534] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.419109] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.421052] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.424033] pci 0000:00:02.0: [1af4:1000] type 00 class 0x020000 [ 0.431019] pci 0000:00:02.0: reg 0x10: [io 0xc300-0xc31f] [ 0.444022] pci 0000:00:02.0: reg 0x20: [mem 0xe0000000000-0xe0000003fff 64bit pref] [ 0.450017] pci 0000:00:02.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref] [ 0.456304] pci 0000:00:05.0: [1af4:1001] type 00 class 0x010000 [ 0.463019] pci 0000:00:05.0: reg 0x10: [io 0xc000-0xc07f] [ 0.470014] pci 0000:00:05.0: reg 0x14: [mem 0xfebc0000-0xfebc0fff] [ 0.489018] pci 0000:00:05.0: reg 0x20: [mem 0xe0000004000-0xe0000007fff 64bit pref] [ 0.501061] pci 0000:00:06.0: [1af4:1001] type 00 class 0x010000 [ 0.507018] pci 0000:00:06.0: reg 0x10: [io 0xc080-0xc0ff] [ 0.512015] pci 0000:00:06.0: reg 0x14: [mem 0xfebc1000-0xfebc1fff] [ 0.528018] pci 0000:00:06.0: reg 0x20: [mem 0xe0000008000-0xe000000bfff 64bit pref] [ 0.540407] pci 0000:00:07.0: [1af4:1001] type 00 class 0x010000 [ 0.546016] pci 0000:00:07.0: reg 0x10: [io 0xc100-0xc17f] [ 0.553016] pci 0000:00:07.0: reg 0x14: [mem 0xfebc2000-0xfebc2fff] [ 0.571018] pci 0000:00:07.0: reg 0x20: [mem 0xe000000c000-0xe000000ffff 64bit pref] [ 0.581914] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 [ 0.590019] pci 0000:00:08.0: reg 0x10: [io 0xc180-0xc1ff] [ 0.595017] pci 0000:00:08.0: reg 0x14: [mem 0xfebc3000-0xfebc3fff] [ 0.614018] pci 0000:00:08.0: reg 0x20: [mem 0xe0000010000-0xe0000013fff 64bit pref] [ 0.626889] pci 0000:00:09.0: [1af4:1001] type 00 class 0x010000 [ 0.636020] pci 0000:00:09.0: reg 0x10: [io 0xc200-0xc27f] [ 0.643022] pci 0000:00:09.0: reg 0x14: [mem 0xfebc4000-0xfebc4fff] [ 0.663017] pci 0000:00:09.0: reg 0x20: [mem 0xe0000014000-0xe0000017fff 64bit pref] [ 0.674222] pci 0000:00:0a.0: [1af4:1001] type 00 class 0x010000 [ 0.681013] pci 0000:00:0a.0: reg 0x10: [io 0xc280-0xc2ff] [ 0.692015] pci 0000:00:0a.0: reg 0x14: [mem 0xfebc5000-0xfebc5fff] [ 0.711015] pci 0000:00:0a.0: reg 0x20: [mem 0xe0000018000-0xe000001bfff 64bit pref] [ 0.721624] ACPI: PCI: Interrupt link LNKA configured for IRQ 10 [ 0.725485] ACPI: PCI: Interrupt link LNKB configured for IRQ 10 [ 0.727354] ACPI: PCI: Interrupt link LNKC configured for IRQ 11 [ 0.730401] ACPI: PCI: Interrupt link LNKD configured for IRQ 11 [ 0.734284] ACPI: PCI: Interrupt link LNKS configured for IRQ 9 [ 0.738204] iommu: Default domain type: Passthrough [ 0.739000] SCSI subsystem initialized [ 0.741161] ACPI: bus type USB registered [ 0.742099] usbcore: registered new interface driver usbfs [ 0.744070] usbcore: registered new interface driver hub [ 0.746074] usbcore: registered new device driver usb [ 0.748164] pps_core: LinuxPPS API ver. 1 registered [ 0.750013] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 0.754072] PTP clock support registered [ 0.757093] EDAC MC: Ver: 3.0.0 [ 0.760158] PCI: Using ACPI for IRQ routing [ 0.761977] NetLabel: Initializing [ 0.763017] NetLabel: domain hash size = 128 [ 0.765013] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.766120] NetLabel: unlabeled traffic allowed by default [ 0.769117] vgaarb: loaded [ 0.771038] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.772015] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.778000] clocksource: Switched to clocksource kvm-clock [ 0.889476] VFS: Disk quotas dquot_6.6.0 [ 0.891876] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.894520] *** VALIDATE ramfs *** [ 0.895504] *** VALIDATE hugetlbfs *** [ 0.896997] pnp: PnP ACPI init [ 0.899343] pnp: PnP ACPI: found 6 devices [ 0.916250] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 0.919642] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 0.922214] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 0.924479] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 0.927165] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 0.930298] pci_bus 0000:00: resource 8 [mem 0xe0000000000-0xe007fffffff window] [ 0.932779] NET: Registered protocol family 2 [ 0.934804] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc) [ 0.939711] tcp_listen_portaddr_hash hash table entries: 4096 (order: 5, 163840 bytes, vmalloc) [ 0.942813] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc) [ 0.947646] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc) [ 0.950938] TCP: Hash tables configured (established 65536 bind 65536) [ 0.953773] MPTCP token hash table entries: 8192 (order: 6, 393216 bytes, vmalloc) [ 0.956400] UDP hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.958958] UDP-Lite hash table entries: 4096 (order: 6, 393216 bytes, vmalloc) [ 0.961776] NET: Registered protocol family 1 [ 0.965368] RPC: Registered named UNIX socket transport module. [ 0.967765] RPC: Registered udp transport module. [ 0.969362] RPC: Registered tcp transport module. [ 0.971092] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.973599] NET: Registered protocol family 44 [ 0.976687] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 0.978221] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 0.979942] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 0.981890] PCI: CLS 0 bytes, default 64 [ 0.983399] Unpacking initramfs... [ 2.387790] debug: unmapping init [mem 0xffff8b8b7cc54000-0xffff8b8b7ffbffff] [ 2.391936] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 2.394309] software IO TLB: mapped [mem 0x00000000a8000000-0x00000000ac000000] (64MB) [ 2.397754] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229835b7123, max_idle_ns: 440795242976 ns [ 2.876904] Initialise system trusted keyrings [ 2.878706] Key type blacklist registered [ 2.881364] workingset: timestamp_bits=36 max_order=20 bucket_order=0 [ 2.891205] zbud: loaded [ 2.895051] *** VALIDATE nfs *** [ 2.896448] *** VALIDATE nfs4 *** [ 2.897740] pstore: using deflate compression [ 2.901551] Platform Keyring initialized [ 2.995381] NET: Registered protocol family 38 [ 2.996700] Key type asymmetric registered [ 2.997756] Asymmetric key parser 'x509' registered [ 2.998970] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 3.001511] io scheduler mq-deadline registered [ 3.003239] io scheduler kyber registered [ 3.004995] io scheduler bfq registered [ 3.006828] atomic64_test: passed for x86-64 platform with CX8 and with SSE [ 3.009460] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 3.012220] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 3.014982] ACPI: Power Button [PWRF] [ 3.019501] ACPI: \_SB_.LNKB: Enabled at IRQ 10 [ 3.025900] ACPI: \_SB_.LNKA: Enabled at IRQ 11 [ 3.037711] ACPI: \_SB_.LNKC: Enabled at IRQ 11 [ 3.042953] ACPI: \_SB_.LNKD: Enabled at IRQ 10 [ 3.058407] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 3.084070] 00:03: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A [ 3.110548] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A [ 3.114817] Non-volatile memory driver v1.3 [ 3.116198] Linux agpgart interface v0.103 [ 3.147851] virtio_blk virtio1: [vda] 146648 512-byte logical blocks (75.1 MB/71.6 MiB) [ 3.152322] vda: detected capacity change from 0 to 75083776 [ 3.170052] virtio_blk virtio2: [vdb] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB) [ 3.173882] vdb: detected capacity change from 0 to 1073741824 [ 3.191939] virtio_blk virtio3: [vdc] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.196538] vdc: detected capacity change from 0 to 2621440000 [ 3.212762] virtio_blk virtio4: [vdd] 5120000 512-byte logical blocks (2.62 GB/2.44 GiB) [ 3.215684] vdd: detected capacity change from 0 to 2621440000 [ 3.229313] virtio_blk virtio5: [vde] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.232658] vde: detected capacity change from 0 to 4294967296 [ 3.246176] virtio_blk virtio6: [vdf] 8388608 512-byte logical blocks (4.29 GB/4.00 GiB) [ 3.250356] vdf: detected capacity change from 0 to 4294967296 [ 3.257174] libphy: Fixed MDIO Bus: probed [ 3.261944] usbcore: registered new interface driver usbserial_generic [ 3.264680] usbserial: USB Serial support registered for generic [ 3.266969] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 3.270349] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 3.272259] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 3.274540] mousedev: PS/2 mouse device common for all mice [ 3.277604] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 3.279835] rtc_cmos 00:05: RTC can wake from S4 [ 3.286112] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 3.288076] rtc_cmos 00:05: registered as rtc0 [ 3.291684] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 3.293278] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3 [ 3.294690] intel_pstate: CPU model not supported [ 3.301302] hid: raw HID events driver (C) Jiri Kosina [ 3.303368] usbcore: registered new interface driver usbhid [ 3.304771] usbhid: USB HID core driver [ 3.305961] drop_monitor: Initializing network drop monitor service [ 3.307776] Initializing XFRM netlink socket [ 3.309476] NET: Registered protocol family 10 [ 3.311915] Segment Routing with IPv6 [ 3.313196] NET: Registered protocol family 17 [ 3.314989] mpls_gso: MPLS GSO support [ 3.324767] RAS: Correctable Errors collector initialized. [ 3.326848] AVX version of gcm_enc/dec engaged. [ 3.328414] AES CTR mode by8 optimization enabled [ 3.402417] sched_clock: Marking stable (3402338639, 0)->(4248314497, -845975858) [ 3.406606] registered taskstats version 1 [ 3.408820] Loading compiled-in X.509 certificates [ 3.410932] zswap: loaded using pool lzo/zbud [ 3.433395] Key type big_key registered [ 3.444869] Key type encrypted registered [ 3.446599] ima: No TPM chip found, activating TPM-bypass! [ 3.448959] ima: Allocated hash algorithm: sha1 [ 3.450586] ima: No architecture policies found [ 3.451858] evm: Initialising EVM extended attributes: [ 3.453320] evm: security.selinux [ 3.454577] evm: security.ima [ 3.455744] evm: security.capability [ 3.456827] evm: HMAC attrs: 0x1 [ 3.458962] rtc_cmos 00:05: setting system clock to 2026-09-07 09:57:30 UTC (1788775050) [ 3.464956] debug: unmapping init [mem 0xffffffffb0003000-0xffffffffb01fffff] [ 3.468080] debug: unmapping init [mem 0xffffffffaed82000-0xffffffffaf058fff] [ 3.480064] Write protecting the kernel read-only data: 28672k [ 3.483257] debug: unmapping init [mem 0xffffffffad403000-0xffffffffad5fffff] [ 3.485373] debug: unmapping init [mem 0xffffffffadd14000-0xffffffffaddfffff] [ 3.515951] 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.522345] systemd[1]: Detected virtualization kvm. [ 3.525233] systemd[1]: Detected architecture x86-64. [ 3.527235] systemd[1]: Running in initial RAM disk. Welcome to Rocky Linux 8.10 (Green Obsidian) dracut-049-233.git20240115.el8 (Initramfs)! [ 3.554947] systemd[1]: No hostname configured. [ 3.558056] systemd[1]: Set hostname to . [ 3.559625] random: systemd: uninitialized urandom read (16 bytes read) [ 3.561706] systemd[1]: Initializing machine ID from random generator. [ 3.609123] random: ln: uninitialized urandom read (6 bytes read) [ 3.695796] random: systemd: uninitialized urandom read (16 bytes read) [ 3.699197] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 3.708434] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... [ 3.715174] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ OK ] Started Memstrack Anylazing Service. Starting Create list of required st…ce nodes for the current kernel... Starting Apply Kernel Variables... Starting Create Volatile Files and Directories... [ OK ] Reached target Timers. [ OK ] Reached target Initrd Root Device. [ OK ] Listening on udev Kernel Socket. [ OK ] Listening on Journal Socket (/dev/log). [ OK ] Listening on udev Control Socket. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Reached target Sockets. [ OK ] Reached target Slices. [ OK ] Reached target Swap. Starting Journal Service... [ OK ] Started Setup Virtual Console. [ OK ] Started Create list of required sta…vice nodes for the current kernel. [ OK ] Started Apply Kernel Variables. [ OK ] Started Create Volatile Files and Directories. Starting Create Static Device Nodes in /dev... Starting dracut cmdline hook... [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started Journal Service. [ OK ] Started dracut cmdline hook. Starting dracut pre-udev hook... [ 4.334448] device-mapper: uevent: version 1.0.3 [ 4.336623] 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. [ 5.068186] virtio_net virtio0 ens2: renamed from eth0 [ 5.075295] random: fast init done [ 5.106581] scsi host0: ata_piix [ 5.110822] scsi host1: ata_piix [ 5.112697] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc320 irq 14 [ 5.114864] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc328 irq 15 [ 9.359733] dracut-initqueue[593]: RTNETLINK answers: File exists [ 9.961754] random: crng init done [ 9.962930] random: 7 urandom warning(s) missed due to ratelimiting Starting nbd nbd0... [ OK ] Started nbd nbd0. [ OK ] Started dracut initqueue hook. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Mounting /sysroot... [ 10.253344] 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. Stopping Hardware RNG Entropy Gatherer Daemon... [ OK ] Stopped dracut pre-pivot and cleanup hook. [ OK ] Stopped target Remote File Systems. [ OK ] Stopped target Remote File Systems (Pre). [ OK ] Stopped dracut initqueue hook. [ OK ] Stopped target Initrd Default Target. [ OK ] Stopped target Initrd Root Device. [ OK ] Stopped Hardware RNG Entropy Gatherer Daemon. [ OK ] Stopped target Basic System. [ OK ] Stopped target Paths. [ OK ] Stopped target Sockets. [ OK ] Stopped target Slices. [ OK ] Stopped target System Initialization. [ OK ] Stopped target Swap. [ OK ] Stopped Apply Kernel Variables. [ 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. [ OK ] Stopped udev Coldplug all Devices. [ OK ] Stopped dracut pre-trigger hook. Stopping udev Kernel Device Manager... [ OK ] Started Cleaning Up and Shutting Down Daemons. [ OK ] Stopped udev Kernel Device Manager. [ OK ] Stopped dracut pre-udev hook. [ OK ] Stopped dracut cmdline hook. [ OK ] Stopped Create Static Device Nodes in /dev. [ OK ] Stopped Create list of required sta…vice nodes for the current kernel. [ OK ] Closed udev Control Socket. [ OK ] Closed udev Kernel Socket. Starting Cleanup udevd DB... [ OK ] Started Cleanup udevd DB. [ OK ] Reached target Switch Root. Starting Switch Root... [ 11.339364] printk: systemd: 26 output lines suppressed due to ratelimiting [ 11.569274] SELinux: Disabled at runtime. [ 11.630372] 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.638400] systemd[1]: Detected virtualization kvm. [ 11.639932] systemd[1]: Detected architecture x86-64. Welcome to Rocky Linux 8.10 (Green Obsidian)! [ 12.088611] systemd[1]: initrd-switch-root.service: Succeeded. [ 12.092567] systemd[1]: Stopped Switch Root. [ OK ] Stopped Switch Root. [ 12.100848] systemd[1]: systemd-journald.service: Service has no hold-off time (RestartSec=0), scheduling restart. [ 12.104126] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1. [ 12.107332] systemd[1]: Stopped Journal Service. [ OK ] Stopped Journal Service. [ 12.113168] systemd[1]: Starting Journal Service... Starting Journal Service... [ 12.118424] systemd[1]: Created slice system-sshd\x2dkeygen.slice. [ OK ] Created slice system-sshd\x2dkeygen.slice. [ OK ] Listening on udev Control Socket. [ OK ] Created slice system-serial\x2dgetty.slice. [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... Mounting POSIX Message Queue File System... [ OK ] Listening on udev Kernel Socket. [ OK ] Created slice system-getty.slice. Starting udev Coldplug all Devices... Starting Remount Root and Kernel File Systems... [ OK ] Started Forward Password Requests to Wall Directory Watch. [ OK ] Reached target rpc_pipefs.target. Starting Create list of required st…ce nodes for the current kernel... [ OK ] Listening on RPCbind Server Activation Socket. [ OK ] Stopped target Switch Root. [ OK ] Stopped target Initrd Root File System. [ OK ] Stopped target Initrd File Systems. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ OK ] Reached target Paths. [ OK ] Reached target Local Encrypted Volumes. [ OK ] Listening on initctl Compatibility Named Pipe. Mounting Huge Pages File System... [ OK ] Created slice User and Session Slice. [ OK ] Reached target Slices. Starting Apply Kernel Variables... Activating swap /dev/disk/by-label/SWAP... [ OK ] Reached target RPC Port Mapper. [ OK ] Listening on Process Core Dump Socket. [ 12.271582] Adding 1048572k swap on /dev/vdb. Priority:-2 extents:1 across:1048572k FS [ OK ] Started Journal Service. [ OK ] Mounted Kernel Debug File System. [ OK ] Mounted POSIX Message Queue File System. [FAILED] Failed to start Remount Root and Kernel File Systems. See 'systemctl status systemd-remount-fs.service' for details. [ 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 ] Reached target Swap. Starting Configure read-only root support... Starting Create Static Device Nodes in /dev... Starting Flush Journal to Persistent Storage... [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started Create Static Device Nodes in /dev. [ OK ] Started udev Coldplug all Devices. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /mnt... Mounting /home/green/git/lustre-release... [ OK ] Mounted /mnt. [ 12.520355] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ OK ] Mounted /home/green/git/lustre-release. [ OK ] Started udev Kernel Device Manager. [ 12.762128] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0 [ 12.783580] input: PC Speaker as /devices/platform/pcspkr/input/input5 [ 12.896215] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer [ 12.904059] EDAC sbridge: Ver: 1.1.2 [ 14.507024] Key type dns_resolver registered [ 14.810344] NFS: Registering the id_resolver key type [ 14.812092] Key type id_resolver registered [ 14.813594] 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 RPC Bind... Starting Update UTMP about System Boot/Shutdown... [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Started RPC Bind. [ OK ] Started Rebuild Dynamic Linker Cache. Starting Update is Completed... [ OK ] Started Update is Completed. [ OK ] Reached target System Initialization. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Started daily update of the root trust anchor for DNSSEC. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Started dnf makecache --timer. [ OK ] Reached target Timers. [ OK ] Reached target Basic System. [ OK ] Started irqbalance daemon. [ OK ] Started Hardware RNG Entropy Gatherer Daemon. [ OK ] Reached target sshd-keygen.target. Starting Restore /run/initramfs on shutdown... Starting Login Service... [ OK ] Started D-Bus System Message Bus. Starting Network Manager... [ OK ] Started Restore /run/initramfs on shutdown. [ OK ] Started Login Service. [ OK ] Started Network Manager. Starting Network Manager Wait Online... [ OK ] Reached target Network. Starting Dynamic System Tuning Daemon... Starting OpenSSH server daemon... Starting GSSAPI Proxy Daemon... Starting Hostname Service... [ OK ] Started GSSAPI Proxy Daemon. [ OK ] Started OpenSSH server daemon. [ OK ] Reached target NFS client services. [ OK ] Reached target Remote File Systems (Pre). [ OK ] Reached target Remote File Systems. Starting Permit User Sessions... [ OK ] Started Permit User Sessions. [ OK ] Started Serial Getty on ttyS1. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. [ OK ] Started Command Scheduler. [ OK ] Started Hostname Service. Starting Network Manager Script Dispatcher Service... [ OK ] Started Network Manager Script Dispatcher Service. [ OK ] Started Network Manager Wait Online. [ OK ] Reached target Network is Online. Starting 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... [ OK ] Started Authorization Manager. [ OK ] Started Dynamic System Tuning Daemon. [ OK ] Reached target Multi-User System. [ OK ] Reached target Graphical Interface. Starting Update UTMP about System Runlevel Changes... [ OK ] Started Update UTMP about System Runlevel Changes. Rocky Linux 8.10 (Green Obsidian) Kernel 4.18.0rh8.10-debug on an x86_64 oleg615-server login: [ 40.901069] libcfs: loading out-of-tree module taints kernel. [ 40.932412] Key type ._llcrypt registered [ 40.933650] Key type .llcrypt registered [ 40.988807] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_hostid [ 50.155266] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 50.818813] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 50.826652] alg: No test for adler32 (adler32-zlib) [ 51.880953] Lustre: Lustre: Build Version: 2.17.57_103_g80273de [ 52.260026] LNet: Added LNI 192.168.206.115@tcp [8/256/0/180] [ 53.911219] Key type lgssc registered [ 54.580683] Lustre: Echo OBD driver; http://www.lustre.org/ [ 60.702956] ZFS: Loaded module v2.3.2-1, ZFS pool version 5000, ZFS filesystem version 5 [ 82.307687] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 90.006638] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 90.023281] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 91.182777] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 91.212588] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 91.285183] Lustre: lustre-MDT0000: new disk, initializing [ 91.333904] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 91.348061] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 94.322220] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 102.033756] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 102.082634] Lustre: 6480:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 102.098894] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 102.102482] Lustre: Skipped 1 previous similar message [ 102.152807] Lustre: lustre-MDT0001: new disk, initializing [ 102.193197] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 102.211868] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 102.217815] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 104.396259] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 107.502147] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 107.828093] hrtimer: interrupt took 2851776 ns [ 113.170229] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 113.319330] Lustre: lustre-OST0000: new disk, initializing [ 113.322142] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 113.326850] Lustre: 8418:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 113.362295] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 115.280136] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 115.290148] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 115.329209] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 116.407892] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 123.768955] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 123.838425] Lustre: lustre-OST0001: new disk, initializing [ 123.841309] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 123.845228] Lustre: 9490:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 123.887992] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 124.447546] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 124.456057] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 124.485160] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 126.867760] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 133.735527] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 137.674318] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 140.157305] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing check_logdir /tmp/testlogs/ [ 142.003394] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing yml_node [ 143.795589] Lustre: DEBUG MARKER: Client: 2.17.57.103 [ 144.728805] Lustre: DEBUG MARKER: MDS: 2.17.57.103 [ 145.653815] Lustre: DEBUG MARKER: OSS: 2.17.57.103 [ 146.292960] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-lfsck ============----- Mon Sep 7 05:59:53 EDT 2026 [ 152.575331] Lustre: DEBUG MARKER: excepting tests: 18b 23b [ 156.234767] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 158.688582] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 158.692538] 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 [ 158.698236] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 160.225440] 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 [ 160.225803] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 160.230647] Lustre: Skipped 2 previous similar messages [ 160.233370] Lustre: Skipped 2 previous similar messages [ 164.694431] Lustre: server umount lustre-MDT0000 complete [ 167.606094] LustreError: 6475:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788775214 with bad export cookie 15035752923779109538 [ 167.607569] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 167.613037] LustreError: 6475:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 167.715245] Lustre: server umount lustre-MDT0001 complete [ 180.994308] Lustre: server umount lustre-OST0000 complete [ 193.234028] Lustre: server umount lustre-OST0001 complete [ 198.819860] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing unload_modules_local [ 199.977413] Key type lgssc unregistered [ 200.124359] LNet: 14750:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 200.128156] LNetError: 14750:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 200.138460] LNet: Removed LNI 192.168.206.115@tcp [ 200.518154] Key type .llcrypt unregistered [ 200.519960] Key type ._llcrypt unregistered [ 208.865877] Key type ._llcrypt registered [ 208.867495] Key type .llcrypt registered [ 208.908133] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_hostid [ 215.410114] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 215.758864] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 215.766973] alg: No test for adler32 (adler32-zlib) [ 216.653925] Lustre: Lustre: Build Version: 2.17.57_103_g80273de [ 216.779911] LNet: Added LNI 192.168.206.115@tcp [8/256/0/180] [ 218.399107] Key type lgssc registered [ 218.812267] Lustre: Echo OBD driver; http://www.lustre.org/ [ 237.676861] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 242.719928] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 242.726426] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 243.826790] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 243.838486] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 243.878461] Lustre: lustre-MDT0000: new disk, initializing [ 243.908953] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 243.919958] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 245.725923] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 253.523496] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 253.569627] Lustre: 19183:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 253.587287] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 253.590268] Lustre: Skipped 1 previous similar message [ 253.639367] Lustre: lustre-MDT0001: new disk, initializing [ 253.678125] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 253.697266] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 253.703065] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 255.973185] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 259.354589] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 264.664437] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 264.778304] Lustre: lustre-OST0000: new disk, initializing [ 264.780489] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 264.784168] Lustre: 21122:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 264.814361] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 265.907916] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 265.914025] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 265.933936] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 267.352552] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 274.260205] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 274.311746] Lustre: lustre-OST0001: new disk, initializing [ 274.314392] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 274.320771] Lustre: 22144:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 274.359968] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 277.250300] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 283.649178] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 283.656064] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 283.677694] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 284.711497] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 287.892192] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 291.288632] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 06:02:18 (1788775338) === [ 292.528507] Lustre: DEBUG MARKER: == sanity-lfsck test 0: Control LFSCK manually =========== 06:02:19 (1788775339) [ 292.652045] Lustre: 19190:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 292.656423] Lustre: 19190:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 292.660361] Lustre: 19190:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 292.668702] Lustre: 19190:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 292.675118] Lustre: 19190:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 292.678378] Lustre: 19190:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 293.154536] Lustre: 19189:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 293.161208] Lustre: 19189:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 35 previous similar messages [ 293.167422] Lustre: 19189:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 293.171635] Lustre: 19189:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 293.176557] Lustre: 19189:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 293.179899] Lustre: 19189:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 293.183677] Lustre: 19189:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 293.189348] Lustre: 19189:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 293.193232] Lustre: 19189:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 293.196782] Lustre: 19189:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 293.200365] Lustre: 19189:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 293.203395] Lustre: 19189:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 35 previous similar messages [ 294.164848] Lustre: 19191:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 294.169605] Lustre: 19191:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 86 previous similar messages [ 294.172896] Lustre: 19191:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 294.177330] Lustre: 19191:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 86 previous similar messages [ 294.180842] Lustre: 19191:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 294.184450] Lustre: 19191:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 86 previous similar messages [ 294.188559] Lustre: 19191:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 294.192857] Lustre: 19191:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 86 previous similar messages [ 294.196399] Lustre: 19191:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 294.200498] Lustre: 19191:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 86 previous similar messages [ 294.205457] Lustre: 19191:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 294.210400] Lustre: 19191:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 86 previous similar messages [ 296.515433] Lustre: *** cfs_fail_loc=1600, val=3*** [ 298.078746] Lustre: 21108:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0001: opcode 2: before 259 < left 274, rollback = 2 [ 298.084609] Lustre: 21108:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 146 previous similar messages [ 298.090035] Lustre: 23593:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 298.093822] Lustre: 21108:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 298.101564] Lustre: 23593:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 147 previous similar messages [ 298.101584] Lustre: 23593:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 298.101589] Lustre: 23593:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 146 previous similar messages [ 298.101595] Lustre: 23593:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 298.101599] Lustre: 23593:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 146 previous similar messages [ 298.101605] Lustre: 23593:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 298.101609] Lustre: 23593:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 146 previous similar messages [ 298.153819] Lustre: 21108:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 155 previous similar messages [ 298.702473] Lustre: *** cfs_fail_loc=1600, val=3*** [ 303.198313] Lustre: 23598:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 274, rollback = 2 [ 303.198495] Lustre: 21110:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 303.206273] Lustre: 23598:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 22 previous similar messages [ 303.206301] Lustre: 23598:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 2/274/0 [ 303.206305] Lustre: 23598:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 13 previous similar messages [ 303.206311] Lustre: 23598:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 7/225/0 [ 303.206314] Lustre: 23598:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 303.206319] Lustre: 23598:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 303.206323] Lustre: 23598:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 303.206327] Lustre: 23598:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 303.206330] Lustre: 23598:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 22 previous similar messages [ 303.269582] Lustre: 21110:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 48 previous similar messages [ 309.216355] 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 [ 309.217116] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 309.221322] Lustre: Skipped 3 previous similar messages [ 309.224289] Lustre: Skipped 2 previous similar messages [ 312.558847] Lustre: server umount lustre-MDT0000 complete [ 314.327843] LustreError: 19174:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788775361 with bad export cookie 5481998265368199054 [ 314.330818] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 314.335937] LustreError: 19174:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 314.346424] 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 [ 314.347220] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 314.352081] Lustre: Skipped 1 previous similar message [ 314.358072] Lustre: Skipped 2 previous similar messages [ 314.491757] Lustre: server umount lustre-MDT0001 complete [ 322.386641] Lustre: server umount lustre-OST0000 complete [ 324.137055] Lustre: server umount lustre-OST0001 complete [ 327.700936] Lustre: DEBUG MARKER: == sanity-lfsck test 1a: LFSCK can find out and repair crashed FID-in-dirent ========================================================== 06:02:54 (1788775374) [ 333.895055] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 338.783045] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 338.944584] LustreError: 26253:0:(ldlm_lib.c:1190: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. [ 338.955125] LustreError: 26253:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 338.968913] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 340.797995] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 344.032566] LustreError: 26254:0:(ldlm_lib.c:1190: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. [ 344.708292] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 346.882455] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 348.383210] Lustre: 27394:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 351.429746] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 351.592249] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 351.596450] Lustre: Skipped 1 previous similar message [ 354.665425] LustreError: 27748:0:(ldlm_lib.c:1190: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. [ 354.848878] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 358.967620] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 362.440095] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 364.199429] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:40 to 0x280000401:65) [ 364.202217] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:41 to 0x2c0000401:65) [ 371.485980] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 373.073841] Lustre: 29266:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 373.820645] Lustre: 26249:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 373.824851] Lustre: 26249:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 52 previous similar messages [ 373.827587] Lustre: 26249:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 373.830084] Lustre: 26249:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 26 previous similar messages [ 373.833554] Lustre: 26249:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 373.836432] Lustre: 26249:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 373.839051] Lustre: 26249:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 373.842426] Lustre: 26249:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 373.844893] Lustre: 26249:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 373.847787] Lustre: 26249:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 373.850933] Lustre: 26249:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 373.855173] Lustre: 26249:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 53 previous similar messages [ 376.127633] Lustre: *** cfs_fail_loc=1501, val=0*** [ 379.881721] Lustre: Failing over lustre-MDT0000 [ 380.023621] Lustre: server umount lustre-MDT0000 complete [ 380.896465] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 380.898717] 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 [ 380.910153] LustreError: 26253:0:(ldlm_lib.c:1190: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. [ 384.994602] LustreError: 26254:0:(ldlm_lib.c:1190: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. [ 384.995492] 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 [ 385.012133] Lustre: Skipped 2 previous similar messages [ 385.371658] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 385.429760] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 385.555255] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 385.559192] Lustre: Skipped 1 previous similar message [ 387.651385] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 388.853801] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 388.862290] Lustre: lustre-MDT0000: Denying connection for new client 764c3ff1-28ec-4b6c-928b-055e966b770b (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 390.631967] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 390.646968] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 390.670687] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:105 to 0x2c0000401:129) [ 390.673412] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:105 to 0x280000401:129) [ 394.981328] Lustre: *** cfs_fail_loc=1505, val=0*** [ 399.178464] Lustre: DEBUG MARKER: == sanity-lfsck test 1b: LFSCK can find out and repair the missing FID-in-LMA ========================================================== 06:04:06 (1788775446) [ 399.992641] Lustre: 26250:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 256 < left 278, rollback = 2 [ 399.998663] Lustre: 26250:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 322 previous similar messages [ 400.002686] Lustre: 26250:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 400.005448] Lustre: 26250:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 400.009304] Lustre: 26250:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 400.012552] Lustre: 26250:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 400.015459] Lustre: 26250:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 400.018131] Lustre: 26250:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 400.021496] Lustre: 26250:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 400.025087] Lustre: 26250:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 400.029796] Lustre: 26250:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 400.035288] Lustre: 26250:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 322 previous similar messages [ 403.494175] Lustre: *** cfs_fail_loc=1502, val=0*** [ 408.776786] Lustre: Failing over lustre-MDT0000 [ 408.935271] Lustre: server umount lustre-MDT0000 complete [ 411.105925] 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 [ 411.108927] LustreError: 26249:0:(ldlm_lib.c:1190: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. [ 411.119024] Lustre: Skipped 2 previous similar messages [ 411.126901] LustreError: 26249:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 4 previous similar messages [ 411.134493] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 414.734617] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 414.835115] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 417.793401] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 419.112893] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 419.117541] Lustre: lustre-MDT0000: Denying connection for new client 53a417c5-51c2-44e6-8783-321154f5c357 (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 420.325904] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 420.330482] Lustre: Skipped 3 previous similar messages [ 420.338680] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 420.373808] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:169 to 0x280000401:193) [ 420.374538] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:169 to 0x2c0000401:193) [ 425.121354] Lustre: *** cfs_fail_loc=1505, val=0*** [ 429.058952] Lustre: DEBUG MARKER: == sanity-lfsck test 1c: LFSCK can find out and repair lost FID-in-dirent ========================================================== 06:04:36 (1788775476) [ 432.011434] Lustre: 26248:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 260 < left 278, rollback = 2 [ 432.017447] Lustre: 26248:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 505 previous similar messages [ 432.023644] Lustre: 26248:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 432.031684] Lustre: 26248:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 505 previous similar messages [ 432.037502] Lustre: 26248:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 432.045279] Lustre: 26248:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 505 previous similar messages [ 432.050830] Lustre: 26248:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 1/3/0 [ 432.056179] Lustre: 26248:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 505 previous similar messages [ 432.061712] Lustre: 26248:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 432.067261] Lustre: 26248:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 505 previous similar messages [ 432.071953] Lustre: 26248:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 432.076325] Lustre: 26248:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 505 previous similar messages [ 433.251272] Lustre: *** cfs_fail_loc=1504, val=0*** [ 433.254333] Lustre: *** cfs_fail_loc=1504, val=0*** [ 433.257280] Lustre: Skipped 1 previous similar message [ 437.479364] Lustre: Failing over lustre-MDT0000 [ 437.640818] Lustre: server umount lustre-MDT0000 complete [ 440.803272] 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 [ 440.803746] LustreError: 29034:0:(ldlm_lib.c:1190: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. [ 440.811154] Lustre: Skipped 4 previous similar messages [ 440.813513] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 440.821319] LustreError: 29034:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 4 previous similar messages [ 443.314090] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 443.369934] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 443.558154] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 443.561749] Lustre: Skipped 1 previous similar message [ 445.960912] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 447.198542] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 447.205540] Lustre: lustre-MDT0000: Denying connection for new client 785a86db-b384-4dcf-bd0d-493c05af8e58 (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 448.996523] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 449.000041] Lustre: Skipped 3 previous similar messages [ 449.009770] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 449.033429] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:233 to 0x2c0000401:257) [ 449.033507] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:233 to 0x280000401:257) [ 453.305136] Lustre: *** cfs_fail_loc=1505, val=0*** [ 456.913923] Lustre: DEBUG MARKER: == sanity-lfsck test 2a: LFSCK can find out and repair crashed linkEA entry ========================================================== 06:05:04 (1788775504) [ 460.876699] Lustre: *** cfs_fail_loc=1603, val=0*** [ 464.506583] Lustre: Failing over lustre-MDT0000 [ 464.637799] Lustre: server umount lustre-MDT0000 complete [ 469.473835] 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 [ 469.480329] Lustre: Skipped 2 previous similar messages [ 470.325702] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 470.430878] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 472.942392] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 474.232533] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 474.237286] Lustre: lustre-MDT0000: Denying connection for new client bb706c6f-357f-4e69-82f3-09e06f9ddd27 (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 475.620119] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 475.624081] Lustre: Skipped 3 previous similar messages [ 475.633156] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 475.656373] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:297 to 0x280000401:321) [ 475.657611] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:297 to 0x2c0000401:321) [ 482.249571] Lustre: DEBUG MARKER: == sanity-lfsck test 2b: LFSCK can find out and remove invalid linkEA entry ========================================================== 06:05:29 (1788775529) [ 485.175462] Lustre: *** cfs_fail_loc=1604, val=0*** [ 487.911390] Lustre: Failing over lustre-MDT0000 [ 488.029638] Lustre: server umount lustre-MDT0000 complete [ 490.975971] LustreError: 29034:0:(ldlm_lib.c:1190: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. [ 490.976607] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 490.984338] LustreError: 29034:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 6 previous similar messages [ 492.509804] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 492.581668] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 494.494730] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 495.477172] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 495.481638] Lustre: lustre-MDT0000: Denying connection for new client 4bc2e4dc-0971-442f-8f8a-c6ab0112c5da (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 498.150750] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 498.156461] Lustre: Skipped 3 previous similar messages [ 498.166049] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 498.187624] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:361 to 0x2c0000401:385) [ 498.189071] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:361 to 0x280000401:385) [ 503.608566] Lustre: DEBUG MARKER: == sanity-lfsck test 2c: LFSCK can find out and remove repeated linkEA entry ========================================================== 06:05:50 (1788775550) [ 504.139547] Lustre: 26248:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 504.144801] Lustre: 26248:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 783 previous similar messages [ 504.147941] Lustre: 26248:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 504.151402] Lustre: 26248:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 784 previous similar messages [ 504.155171] Lustre: 26248:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 504.158830] Lustre: 26248:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 784 previous similar messages [ 504.162825] Lustre: 26248:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 504.166604] Lustre: 26248:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 783 previous similar messages [ 504.170290] Lustre: 26248:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 504.173276] Lustre: 26248:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 784 previous similar messages [ 504.176885] Lustre: 26248:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 504.183475] Lustre: 26248:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 784 previous similar messages [ 506.748228] Lustre: *** cfs_fail_loc=1605, val=0*** [ 509.921433] Lustre: Failing over lustre-MDT0000 [ 510.026809] Lustre: server umount lustre-MDT0000 complete [ 513.504231] 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 [ 513.504904] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 513.509448] Lustre: Skipped 5 previous similar messages [ 514.856384] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 514.915299] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 515.030224] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 515.033501] Lustre: Skipped 2 previous similar messages [ 517.008301] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 518.096810] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 518.101202] Lustre: lustre-MDT0000: Denying connection for new client 303efbf7-dbac-4600-a861-5c9aa3c4b3a6 (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 520.160857] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 520.164925] Lustre: Skipped 3 previous similar messages [ 520.173090] Lustre: lustre-MDT0000: Recovery over after 0:02, of 1 clients 1 recovered and 0 were evicted. [ 520.193898] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:425 to 0x2c0000401:449) [ 520.194033] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:425 to 0x280000401:449) [ 526.208981] Lustre: DEBUG MARKER: == sanity-lfsck test 2d: LFSCK can recover the missing linkEA entry ========================================================== 06:06:13 (1788775573) [ 528.918841] Lustre: *** cfs_fail_loc=161d, val=0*** [ 552.625503] Lustre: Failing over lustre-MDT0000 [ 552.716272] Lustre: server umount lustre-MDT0000 complete [ 555.999471] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 556.001235] LustreError: 26249:0:(ldlm_lib.c:1190: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. [ 556.011444] LustreError: 26249:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 7 previous similar messages [ 556.711282] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 556.774588] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 558.580762] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 559.622854] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 559.628667] Lustre: lustre-MDT0000: Denying connection for new client 28f993f1-f4e4-44ab-8097-d9f18ee202eb (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [ 562.149461] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 562.152199] Lustre: Skipped 3 previous similar messages [ 562.161153] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 562.184045] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:489 to 0x280000401:513) [ 562.187831] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 567.821608] Lustre: DEBUG MARKER: == sanity-lfsck test 2e: namespace LFSCK can verify remote object linkEA ========================================================== 06:06:54 (1788775614) [ 568.985594] Lustre: *** cfs_fail_loc=1603, val=0*** [ 574.449865] Lustre: DEBUG MARKER: == sanity-lfsck test 3: LFSCK can verify multiple-linked objects ========================================================== 06:07:01 (1788775621) [ 577.691744] Lustre: *** cfs_fail_loc=1603, val=0*** [ 578.126124] Lustre: *** cfs_fail_loc=1604, val=0*** [ 583.168558] Lustre: DEBUG MARKER: == sanity-lfsck test 4: FID-in-dirent can be rebuilt after MDT file-level backup/restore ========================================================== 06:07:10 (1788775630) [ 616.044516] Lustre: Failing over lustre-MDT0000 [ 616.171702] Lustre: server umount lustre-MDT0000 complete [ 618.465577] 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 [ 618.473570] Lustre: Skipped 7 previous similar messages [ 618.881232] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 623.443800] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 629.202970] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 629.211945] Lustre: lustre-MDT0000: reset Object Index mappings [ 629.259927] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 629.397649] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 631.357682] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 633.216590] LustreError: 43626:0:(lfsck_engine.c:1018:lfsck_master_engine()) lustre-MDT0000-osd: master engine fail to verify the .lustre/lost+found/, go ahead: rc = -115 [ 633.231242] Lustre: *** cfs_fail_loc=1601, val=1*** [ 634.848472] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 634.849768] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 634.861800] Lustre: Skipped 3 previous similar messages [ 634.876284] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 634.897939] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:609) [ 634.897943] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:609) [ 635.296066] Lustre: *** cfs_fail_loc=1601, val=1*** [ 635.297941] Lustre: Skipped 1 previous similar message [ 638.306354] Lustre: Failing over lustre-MDT0000 [ 638.422813] Lustre: server umount lustre-MDT0000 complete [ 639.968280] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 643.261411] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 643.428500] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 643.430952] Lustre: Skipped 2 previous similar messages [ 643.453061] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 645.288932] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 646.260278] Lustre: lustre-MDT0000: Denying connection for new client b1e0a557-ac4f-4234-9247-8915ad41f94e (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 648.700074] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:592 to 0x280000401:641) [ 648.700073] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:592 to 0x2c0000401:641) [ 651.807392] Lustre: *** cfs_fail_loc=1505, val=0*** [ 655.074903] Lustre: DEBUG MARKER: == sanity-lfsck test 5: LFSCK can handle IGIF object upgrading ========================================================== 06:08:22 (1788775702) [ 655.950826] Lustre: 29029:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 655.955218] Lustre: 29029:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1385 previous similar messages [ 655.961695] Lustre: 29029:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 655.967113] Lustre: 29029:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1385 previous similar messages [ 655.973927] Lustre: 29029:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 655.979293] Lustre: 29029:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1385 previous similar messages [ 655.984159] Lustre: 29029:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 655.988163] Lustre: 29029:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1385 previous similar messages [ 655.992667] Lustre: 29029:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 655.996416] Lustre: 29029:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1385 previous similar messages [ 656.000170] Lustre: 29029:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 656.008491] Lustre: 29029:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1385 previous similar messages [ 656.563663] Lustre: *** cfs_fail_loc=1504, val=0*** [ 661.370955] Lustre: Failing over lustre-MDT0000 [ 661.402904] LustreError: 16348:0:(client.c:1394:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff8b8bed814700 x1875666810913664/t0(0) o6->lustre-OST0000-osc-MDT0000@0@lo:28/4 lens 544/432 e 0 to 0 dl 0 ref 1 fl Rpc:QU/200/ffffffff rc 0/-1 job:'osp-syn-0-0.0' uid:0 gid:0 projid:4294967295 [ 661.554323] Lustre: server umount lustre-MDT0000 complete [ 664.325750] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 669.317425] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 674.282851] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 674.293652] Lustre: lustre-MDT0000: reset Object Index mappings [ 674.538992] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 676.292299] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 677.883522] Lustre: *** cfs_fail_loc=1601, val=1*** [ 679.928439] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:705) [ 679.928626] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:705) [ 686.782356] Lustre: Failing over lustre-MDT0000 [ 686.896126] Lustre: server umount lustre-MDT0000 complete [ 690.143902] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 690.145148] LustreError: 26254:0:(ldlm_lib.c:1190: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. [ 690.148807] LustreError: Skipped 1 previous similar message [ 690.161651] LustreError: 26254:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 31 previous similar messages [ 691.759650] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 692.010596] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 694.014577] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 697.341062] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:681 to 0x280000401:737) [ 697.342941] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:681 to 0x2c0000401:737) [ 700.995360] Lustre: *** cfs_fail_loc=1505, val=0*** [ 700.999492] Lustre: Skipped 84 previous similar messages [ 704.163254] Lustre: DEBUG MARKER: == sanity-lfsck test 6a: LFSCK resumes from last checkpoint (1) ========================================================== 06:09:11 (1788775751) [ 707.931068] Lustre: *** cfs_fail_loc=1600, val=1*** [ 707.934571] Lustre: Skipped 6 previous similar messages [ 719.557273] Lustre: DEBUG MARKER: == sanity-lfsck test 6b: LFSCK resumes from last checkpoint (2) ========================================================== 06:09:26 (1788775766) [ 724.575130] Lustre: *** cfs_fail_loc=1601, val=1*** [ 724.577483] Lustre: Skipped 7 previous similar messages [ 738.636073] Lustre: DEBUG MARKER: == sanity-lfsck test 7a: non-stopped LFSCK should auto restarts after MDS remount (1) ========================================================== 06:09:45 (1788775785) [ 748.446617] Lustre: Failing over lustre-MDT0000 [ 748.512683] Lustre: lustre-MDT0000-osp-MDT0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 748.525112] Lustre: Skipped 12 previous similar messages [ 748.528697] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 748.533427] Lustre: Skipped 3 previous similar messages [ 748.579066] Lustre: server umount lustre-MDT0000 complete [ 753.983345] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 754.253558] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 756.614959] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 759.263804] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 759.266532] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 759.268436] Lustre: Skipped 3 previous similar messages [ 759.274688] Lustre: Skipped 15 previous similar messages [ 759.282245] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 759.290460] Lustre: Skipped 3 previous similar messages [ 759.312800] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:854 to 0x280000401:897) [ 759.312868] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:853 to 0x2c0000401:897) [ 762.572626] Lustre: DEBUG MARKER: == sanity-lfsck test 7b: non-stopped LFSCK should auto restarts after MDS remount (2) ========================================================== 06:10:09 (1788775809) [ 769.092291] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 777.483911] Lustre: 53832:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 788.157945] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 790.017382] Lustre: 54964:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 794.353066] Lustre: *** cfs_fail_loc=1604, val=0*** [ 794.355451] Lustre: Skipped 81 previous similar messages [ 795.993549] Lustre: *** cfs_fail_loc=1602, val=1*** [ 797.023124] Lustre: *** cfs_fail_loc=1602, val=1*** [ 798.049921] Lustre: *** cfs_fail_loc=1602, val=1*** [ 798.478375] Lustre: Failing over lustre-MDT0000 [ 798.652769] Lustre: server umount lustre-MDT0000 complete [ 800.225576] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 800.234829] LustreError: Skipped 1 previous similar message [ 803.567375] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 803.635976] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 803.644868] LustreError: Skipped 4 previous similar messages [ 803.806411] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 805.906113] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 808.959505] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:946 to 0x280000401:961) [ 808.960102] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:947 to 0x2c0000401:993) [ 813.139325] Lustre: DEBUG MARKER: == sanity-lfsck test 8: LFSCK state machine ============== 06:11:00 (1788775860) [ 814.210292] Lustre: server umount lustre-MDT0000 complete [ 815.843266] LustreError: 28575:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788775862 with bad export cookie 5481998265368413212 [ 815.852975] LustreError: 28575:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 819.168547] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 819.175897] Lustre: Skipped 1 previous similar message [ 822.025032] Lustre: server umount lustre-MDT0001 complete [ 823.848569] Lustre: server umount lustre-OST0000 complete [ 825.930463] Lustre: server umount lustre-OST0001 complete [ 829.454536] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_hostid [ 833.007128] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 853.518409] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 858.029749] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 858.130750] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 858.143988] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 858.182804] Lustre: lustre-MDT0000: new disk, initializing [ 858.225849] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 860.347787] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 866.556662] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 866.607155] Lustre: 60112:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 866.627650] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 866.631472] Lustre: Skipped 1 previous similar message [ 866.677385] Lustre: lustre-MDT0001: new disk, initializing [ 866.740564] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 866.748254] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 869.065578] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 872.073488] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 875.415813] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 875.541730] Lustre: 61742:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 877.051798] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 877.091757] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 878.732773] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 884.351726] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 884.417773] Lustre: lustre-OST0001: new disk, initializing [ 884.421582] Lustre: Skipped 1 previous similar message [ 884.424325] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 884.427117] Lustre: Skipped 1 previous similar message [ 884.429704] Lustre: 62612:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 885.816455] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 885.819944] Lustre: Skipped 1 previous similar message [ 885.821487] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 885.852301] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 887.558234] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 892.920086] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 894.579332] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 899.552493] Lustre: *** cfs_fail_loc=1603, val=0*** [ 900.098724] Lustre: *** cfs_fail_loc=1604, val=0*** [ 900.100717] Lustre: Skipped 19 previous similar messages [ 901.946977] Lustre: *** cfs_fail_loc=1601, val=2*** [ 901.955091] Lustre: Skipped 13 previous similar messages [ 914.584302] Lustre: Failing over lustre-MDT0000 [ 914.705071] Lustre: server umount lustre-MDT0000 complete [ 920.169911] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 920.336925] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 920.342560] Lustre: Skipped 8 previous similar messages [ 920.372380] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 922.753877] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 925.664450] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 925.667558] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 925.667883] Lustre: Skipped 1 previous similar message [ 925.672983] Lustre: Skipped 7 previous similar messages [ 925.682495] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 925.685941] Lustre: Skipped 1 previous similar message [ 925.703955] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:65) [ 925.703996] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:65) [ 926.945025] Lustre: Failing over lustre-MDT0000 [ 927.079678] Lustre: server umount lustre-MDT0000 complete [ 930.784798] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 931.541327] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 933.530923] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 935.865358] Lustre: Failing over lustre-MDT0000 [ 935.869854] LustreError: 66630:0:(ldlm_lib.c:3029:target_stop_recovery_thread()) lustre-MDT0000: Aborting recovery [ 935.872921] Lustre: 66082:0:(ldlm_lib.c:2429:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 935.876267] Lustre: lustre-MDT0000-osd: cancel update llog [0x200000400:0x1:0x0] [ 935.887659] Lustre: lustre-MDT0001-osp-MDT0000: cancel update llog [0x240000401:0x1:0x0] [ 935.892758] LustreError: 66082:0:(client.c:1394:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff8b8bf71fd500 x1875666811305728/t0(0) o700->lustre-MDT0001-osp-MDT0000@0@lo:30/10 lens 264/248 e 0 to 0 dl 0 ref 2 fl Rpc:QU/200/ffffffff rc 0/-1 job:'tgt_recover_0.0' uid:0 gid:0 projid:4294967295 [ 935.901273] LustreError: 66082:0:(client.c:1394:ptlrpc_import_delay_req()) Skipped 1 previous similar message [ 935.903954] LustreError: 66082:0:(fid_request.c:217:seq_client_alloc_seq()) cli-cli-lustre-MDT0001-osp-MDT0000: Cannot allocate new meta-sequence: rc = -5 [ 935.907741] LustreError: 66082:0:(fid_request.c:321:seq_client_alloc_fid()) cli-cli-lustre-MDT0001-osp-MDT0000: Can't allocate new sequence: rc = -5 [ 935.923911] Lustre: *** cfs_fail_loc=160b, val=2*** [ 936.013382] Lustre: server umount lustre-MDT0000 complete [ 939.378194] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 941.339799] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 943.707232] Lustre: *** cfs_fail_loc=1602, val=2*** [ 944.632424] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:43 to 0x2c0000401:97) [ 944.633924] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:43 to 0x280000401:97) [ 950.154801] Lustre: DEBUG MARKER: == sanity-lfsck test 9a: LFSCK speed control (1) ========= 06:13:17 (1788775997) [ 956.696657] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 965.429905] Lustre: 69607:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 975.942816] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 982.606564] Lustre: 60119:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 982.611487] Lustre: 60119:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 2990 previous similar messages [ 982.614317] Lustre: 60119:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 982.617808] Lustre: 60119:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 2992 previous similar messages [ 982.621566] Lustre: 60119:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 982.627677] Lustre: 60119:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 2992 previous similar messages [ 982.630572] Lustre: 60119:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 982.633476] Lustre: 60119:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 2991 previous similar messages [ 982.636714] Lustre: 60119:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 982.640217] Lustre: 60119:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 2992 previous similar messages [ 982.643319] Lustre: 60119:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 982.646610] Lustre: 60119:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 2992 previous similar messages [ 1052.648950] Lustre: DEBUG MARKER: == sanity-lfsck test 9b: LFSCK speed control (2) ========= 06:14:59 (1788776099) [ 1078.117162] Lustre: *** cfs_fail_loc=1604, val=0*** [ 1078.119108] Lustre: Skipped 4 previous similar messages [ 1089.857874] Lustre: *** cfs_fail_loc=160c, val=0*** [ 1089.864771] Lustre: Skipped 6 previous similar messages [ 1117.139373] Lustre: DEBUG MARKER: == sanity-lfsck test 10: System is available during LFSCK scanning ========================================================== 06:16:04 (1788776164) [ 1141.599601] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1149.601916] Lustre: *** cfs_fail_loc=1603, val=0*** [ 1149.603751] Lustre: Skipped 1203 previous similar messages [ 1277.298096] Lustre: DEBUG MARKER: == sanity-lfsck test 11a: LFSCK can rebuild lost last_id ========================================================== 06:18:44 (1788776324) [ 1369.568165] 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 [ 1369.568863] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1369.577959] Lustre: Skipped 22 previous similar messages [ 1369.578150] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 1369.580727] Lustre: Skipped 5 previous similar messages [ 1370.862722] Lustre: server umount lustre-MDT0000 complete [ 1372.710549] LustreError: 60103:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788776419 with bad export cookie 5481998265368431846 [ 1372.715267] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1372.717499] LustreError: 60103:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1372.720978] LustreError: Skipped 4 previous similar messages [ 1372.847547] Lustre: server umount lustre-MDT0001 complete [ 1384.979577] Lustre: server umount lustre-OST0000 complete [ 1396.147114] Lustre: server umount lustre-OST0001 complete [ 1399.329536] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 1403.289446] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 1418.783339] LustreError: Failed to get MGS log lustre-sptlrpc and no local copy. [ 1423.903372] LustreError: 75718:0:(mgc_request.c:233:do_config_log_add()) MGC192.168.206.115@tcp: failed processing log, type 4: rc = -110 [ 1449.567227] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 1449.573706] Lustre: Skipped 2 previous similar messages [ 1452.284806] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1454.155265] Lustre: 76299:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1454.165808] Lustre: *** cfs_fail_loc=160e, val=3*** [ 1457.188266] Lustre: 76299:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1462.053936] Lustre: DEBUG MARKER: == sanity-lfsck test 11b: LFSCK can rebuild crashed last_id ========================================================== 06:21:49 (1788776509) [ 1469.048479] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 1473.611302] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1473.791507] LustreError: 75743:0:(ldlm_lib.c:1190: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. [ 1473.806814] LustreError: 75743:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 24 previous similar messages [ 1473.854842] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3240 to 0x280000401:3265) [ 1475.749258] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1480.111677] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1482.284246] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1483.758710] Lustre: 79013:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1483.767258] Lustre: 79013:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 1491.095673] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1493.920481] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1496.548274] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3175 to 0x2c0000401:3201) [ 1497.871464] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1500.099210] Lustre: 77863:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 255 < left 278, rollback = 2 [ 1500.104830] Lustre: 77863:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 37027 previous similar messages [ 1500.108332] Lustre: 77863:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/2, destroy: 0/0/0 [ 1500.110947] Lustre: 77863:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1500.113882] Lustre: 77863:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 1500.117700] Lustre: 77863:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1500.121523] Lustre: 77863:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 1500.125124] Lustre: 77863:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1500.128954] Lustre: 77863:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 1500.132649] Lustre: 77863:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1500.136615] Lustre: 77863:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 1500.140342] Lustre: 77863:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 37027 previous similar messages [ 1501.466957] Lustre: *** cfs_fail_loc=160d, val=0*** [ 1503.947460] Lustre: Failing over lustre-OST0000 [ 1503.989497] Lustre: server umount lustre-OST0000 complete [ 1507.941111] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1508.028790] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1508.034552] Lustre: Skipped 4 previous similar messages [ 1509.601868] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1509.605566] Lustre: Skipped 1 previous similar message [ 1509.614607] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1509.614607] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 1509.615141] Lustre: *** cfs_fail_loc=215, val=0*** [ 1509.619842] Lustre: Skipped 1 previous similar message [ 1509.635464] Lustre: Skipped 7 previous similar messages [ 1510.542309] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1511.950506] Lustre: 81904:0:(ofd_dev.c:561:ofd_lfsck_out_notify()) lustre-OST0000: Found crashed LAST_ID, deny creating new OST-object on the device until the LAST_ID rebuilt successfully. [ 1511.959115] Lustre: 81904:0:(ofd_dev.c:573:ofd_lfsck_out_notify()) lustre-OST0000: Rebuilt crashed LAST_ID files successfully. [ 1513.028272] Lustre: Failing over lustre-OST0000 [ 1513.065504] Lustre: server umount lustre-OST0000 complete [ 1516.513726] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1517.996788] Lustre: *** cfs_fail_loc=215, val=0*** [ 1517.998389] Lustre: Skipped 13 previous similar messages [ 1518.957869] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1521.632849] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1521.635244] Lustre: Skipped 2 previous similar messages [ 1527.548585] Lustre: server umount lustre-MDT0000 complete [ 1529.513290] LustreError: 79015:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788776576 with bad export cookie 5481998265369986378 [ 1529.525680] LustreError: 79015:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1529.683656] Lustre: server umount lustre-MDT0001 complete [ 1542.346304] Lustre: server umount lustre-OST0000 complete [ 1554.460200] Lustre: server umount lustre-OST0001 complete [ 1558.211611] Lustre: DEBUG MARKER: == sanity-lfsck test 12a: single command to trigger LFSCK on all devices ========================================================== 06:23:25 (1788776605) [ 1564.662483] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 1569.513635] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1571.926515] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1576.297085] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1578.308395] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1579.739394] Lustre: 86285:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1579.744496] Lustre: 86285:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 1582.698021] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1585.983663] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1590.150484] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1593.033632] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1594.342821] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3330 to 0x280000401:3361) [ 1594.346379] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3175 to 0x2c0000401:3233) [ 1602.215359] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1617.954929] Lustre: DEBUG MARKER: == sanity-lfsck test 12b: auto detect Lustre device ====== 06:24:25 (1788776665) [ 1625.323553] Lustre: DEBUG MARKER: == sanity-lfsck test 13: LFSCK can repair crashed lmm_oi ========================================================== 06:24:32 (1788776672) [ 1626.087348] Lustre: *** cfs_fail_loc=160f, val=0*** [ 1631.209089] Lustre: DEBUG MARKER: == sanity-lfsck test 14a: LFSCK can repair MDT-object with dangling LOV EA reference (1) ========================================================== 06:24:38 (1788776678) [ 1633.231186] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1633.232641] Lustre: Skipped 7 previous similar messages [ 1673.697686] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1673.701806] Lustre: Skipped 4 previous similar messages [ 1679.875370] Lustre: server umount lustre-MDT0000 complete [ 1681.830814] LustreError: 85124:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788776728 with bad export cookie 5481998265369994890 [ 1681.838946] LustreError: 85124:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1682.008809] Lustre: server umount lustre-MDT0001 complete [ 1694.750350] Lustre: server umount lustre-OST0000 complete [ 1706.606244] Lustre: server umount lustre-OST0001 complete [ 1715.595409] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 1721.051243] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1723.697912] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1727.865162] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1729.956728] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1731.388264] Lustre: 94009:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 1731.393159] Lustre: 94009:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 1734.381360] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1737.193613] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1738.608799] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:161) [ 1740.938624] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1743.294809] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1746.147462] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3522 to 0x280000401:3553) [ 1746.149638] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3285 to 0x2c0000401:3329) [ 1746.151160] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:161) [ 1753.436801] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1759.763823] Lustre: DEBUG MARKER: == sanity-lfsck test 14b: LFSCK can repair MDT-object with dangling LOV EA reference (2) ========================================================== 06:26:46 (1788776806) [ 1763.359102] Lustre: *** cfs_fail_loc=1610, val=0*** [ 1763.361414] Lustre: Skipped 63 previous similar messages [ 1777.120987] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1777.125435] Lustre: Skipped 7 previous similar messages [ 1780.408448] Lustre: server umount lustre-MDT0000 complete [ 1782.239293] LustreError: 92849:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788776829 with bad export cookie 5481998265370023303 [ 1782.244678] LustreError: 92849:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1782.399953] Lustre: server umount lustre-MDT0001 complete [ 1790.402643] Lustre: server umount lustre-OST0000 complete [ 1792.054231] Lustre: server umount lustre-OST0001 complete [ 1798.904098] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 1803.262542] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1805.103342] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1808.880890] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1810.789021] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1814.974794] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1817.703815] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1819.237148] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:116 to 0x280000400:193) [ 1821.614910] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 1824.246232] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1826.789928] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:116 to 0x2c0000400:193) [ 1828.836273] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:3285 to 0x2c0000401:3361) [ 1828.839102] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:3650 to 0x280000401:3681) [ 1833.258859] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 1837.540793] Lustre: DEBUG MARKER: == sanity-lfsck test 15a: LFSCK can repair unmatched MDT-object/OST-object pairs (1) ========================================================== 06:28:04 (1788776884) [ 1838.977151] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1838.982240] Lustre: Skipped 63 previous similar messages [ 1839.067795] Lustre: *** cfs_fail_loc=1611, val=0*** [ 1843.443456] Lustre: DEBUG MARKER: == sanity-lfsck test 15b: LFSCK can repair unmatched MDT-object/OST-object pairs (2) ========================================================== 06:28:10 (1788776890) [ 1844.343727] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1844.345628] Lustre: Skipped 1 previous similar message [ 1844.381317] Lustre: *** cfs_fail_loc=1612, val=0*** [ 1844.384959] Lustre: Skipped 3 previous similar messages [ 1848.957107] Lustre: DEBUG MARKER: == sanity-lfsck test 15c: LFSCK can repair unmatched MDT-object/OST-object pairs (3) ========================================================== 06:28:16 (1788776896) [ 1849.608825] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_15c MDS newer than 2.7.55, LU-6475 [ 1850.504207] Lustre: DEBUG MARKER: == sanity-lfsck test 15d: LFSCK don't crash upon dir migration failure ========================================================== 06:28:17 (1788776897) [ 1854.568946] Lustre: *** cfs_fail_loc=1709, val=0*** [ 1854.572096] LustreError: 98776:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240002340:0x6c:0x0]/f26 failed: rc = -5 [ 1905.633297] 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 [ 1905.633672] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 1905.639177] Lustre: Skipped 19 previous similar messages [ 1905.649244] Lustre: Skipped 5 previous similar messages [ 1910.773526] Lustre: server umount lustre-MDT0000 complete [ 1914.366355] LustreError: 98747:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788776961 with bad export cookie 5481998265370038031 [ 1914.367730] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1914.372458] LustreError: 98747:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 1914.377610] LustreError: Skipped 3 previous similar messages [ 1914.521407] Lustre: server umount lustre-MDT0001 complete [ 1928.530989] Lustre: server umount lustre-OST0000 complete [ 1931.231148] Lustre: 16350:0:(client.c:2503:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1788776962/real 1788776962] req@ffff8b8acec8c000 x1875666815832576/t0(0) o400->lustre-MDT0001-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1788776978 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 1932.374641] Lustre: server umount lustre-OST0001 complete [ 1939.545876] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing unload_modules_local [ 1940.868849] Key type lgssc unregistered [ 1941.015824] LNet: 105602:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 1941.019060] LNetError: 105602:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 1941.026417] LNet: Removed LNI 192.168.206.115@tcp [ 1941.479143] Key type .llcrypt unregistered [ 1941.480421] Key type ._llcrypt unregistered [ 1953.227650] Key type ._llcrypt registered [ 1953.228972] Key type .llcrypt registered [ 1953.275780] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_hostid [ 1960.988797] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 1961.404483] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 1961.449058] alg: No test for adler32 (adler32-zlib) [ 1962.380660] Lustre: Lustre: Build Version: 2.17.57_103_g80273de [ 1962.502056] LNet: Added LNI 192.168.206.115@tcp [8/256/0/180] [ 1964.103177] Key type lgssc registered [ 1964.603559] Lustre: Echo OBD driver; http://www.lustre.org/ [ 1987.862646] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 1994.265048] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 1994.277487] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 1995.392429] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 1995.409932] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 1995.454106] Lustre: lustre-MDT0000: new disk, initializing [ 1995.487706] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1995.495142] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 1997.456901] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2004.471142] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2004.524668] Lustre: 110027:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 2004.546407] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 2004.550620] Lustre: Skipped 1 previous similar message [ 2004.608203] Lustre: lustre-MDT0001: new disk, initializing [ 2004.637459] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2004.653225] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 2004.657324] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 2006.839086] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2009.795899] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 2014.819926] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2014.955203] Lustre: lustre-OST0000: new disk, initializing [ 2014.957493] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 2014.960883] Lustre: 111962:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2014.998302] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2017.814402] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2021.371110] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 2021.379822] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 2021.401598] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 2024.312296] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2024.372390] Lustre: lustre-OST0001: new disk, initializing [ 2024.375323] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 2024.379224] Lustre: 112986:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 2024.418265] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 2026.933956] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2029.560289] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 2029.564463] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 2029.585410] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 2034.011978] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2035.877757] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 2038.319835] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 06:31:25 (1788777085) === [ 2041.156374] Lustre: DEBUG MARKER: == sanity-lfsck test 16: LFSCK can repair inconsistent MDT-object/OST-object owner ========================================================== 06:31:28 (1788777088) [ 2041.289802] Lustre: 110035:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 251 < left 278, rollback = 2 [ 2041.295962] Lustre: 110035:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2041.300195] Lustre: 110035:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2041.308676] Lustre: 110035:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/2 [ 2041.314764] Lustre: 110035:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 2041.318750] Lustre: 110035:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2041.790102] Lustre: 110033:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 2041.793761] Lustre: 110033:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 87 previous similar messages [ 2041.797982] Lustre: 110033:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/1, destroy: 0/0/0 [ 2041.803717] Lustre: 110033:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 2041.808690] Lustre: 110033:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2041.814130] Lustre: 110033:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 2041.817493] Lustre: 110033:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 2/20/0, punch: 0/0/0, quota 7/369/0 [ 2041.823104] Lustre: 110033:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 2041.829819] Lustre: 110033:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/0, delete: 0/0/0 [ 2041.838336] Lustre: 110033:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 2041.844727] Lustre: 110033:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2041.850985] Lustre: 110033:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 87 previous similar messages [ 2042.866852] Lustre: *** cfs_fail_loc=1613, val=0*** [ 2047.512764] Lustre: DEBUG MARKER: == sanity-lfsck test 17: LFSCK can repair multiple references ========================================================== 06:31:34 (1788777094) [ 2048.049879] Lustre: 110034:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 253 < left 278, rollback = 2 [ 2048.055143] Lustre: 110034:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 221 previous similar messages [ 2048.057609] Lustre: 110034:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2048.060556] Lustre: 110034:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 221 previous similar messages [ 2048.063396] Lustre: 110034:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2048.065609] Lustre: 110034:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 221 previous similar messages [ 2048.068667] Lustre: 110034:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 2048.071644] Lustre: 110034:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 221 previous similar messages [ 2048.077407] Lustre: 110034:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2048.081207] Lustre: 110034:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 221 previous similar messages [ 2048.084643] Lustre: 110034:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2048.088768] Lustre: 110034:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 221 previous similar messages [ 2048.657828] Lustre: *** cfs_fail_loc=1614, val=0*** [ 2050.853850] Lustre: 111951:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 259 < left 275, rollback = 2 [ 2050.859820] Lustre: 111951:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 11 previous similar messages [ 2050.863422] Lustre: 111951:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2050.867057] Lustre: 111951:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2050.870641] Lustre: 111951:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/1, xattr_set: 3/275/0 [ 2050.875613] Lustre: 111951:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2050.883694] Lustre: 111951:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 1/4/0, quota 7/225/0 [ 2050.887540] Lustre: 111951:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2050.893857] Lustre: 111951:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 0/0/0, delete: 0/0/0 [ 2050.897246] Lustre: 111951:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2050.900635] Lustre: 111951:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2050.904511] Lustre: 111951:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 11 previous similar messages [ 2053.984400] Lustre: DEBUG MARKER: == sanity-lfsck test 18a: Find out orphan OST-object and repair it (1) ========================================================== 06:31:41 (1788777101) [ 2055.141657] Lustre: *** cfs_fail_loc=1615, val=0*** [ 2055.143228] Lustre: Skipped 1 previous similar message [ 2064.866398] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_18b skipping excluded test 18b [ 2065.683787] Lustre: DEBUG MARKER: == sanity-lfsck test 18c: Find out orphan OST-object and repair it (3) ========================================================== 06:31:52 (1788777112) [ 2065.924620] Lustre: 112593:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 2065.933390] Lustre: 112593:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 23 previous similar messages [ 2065.937548] Lustre: 112593:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2065.941124] Lustre: 112593:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 2065.945318] Lustre: 112593:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2065.949719] Lustre: 112593:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 2065.954216] Lustre: 112593:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2065.959283] Lustre: 112593:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 2065.963431] Lustre: 112593:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 2065.967432] Lustre: 112593:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 2065.971384] Lustre: 112593:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2065.975434] Lustre: 112593:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 23 previous similar messages [ 2067.206878] Lustre: *** cfs_fail_loc=1617, val=0*** [ 2067.261019] Lustre: *** cfs_fail_loc=1617, val=0*** [ 2068.460091] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2068.462255] Lustre: Skipped 5 previous similar messages [ 2078.426803] Lustre: DEBUG MARKER: == sanity-lfsck test 18d: Find out orphan OST-object and repair it (4) ========================================================== 06:32:05 (1788777125) [ 2078.661644] Lustre: 112593:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 278, rollback = 2 [ 2078.667645] Lustre: 112593:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 24 previous similar messages [ 2078.674464] Lustre: 112593:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2078.681484] Lustre: 112593:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 2078.685726] Lustre: 112593:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2078.690148] Lustre: 112593:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 2078.695195] Lustre: 112593:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2078.699365] Lustre: 112593:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 2078.704117] Lustre: 112593:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/1, delete: 0/0/0 [ 2078.708255] Lustre: 112593:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 2078.712644] Lustre: 112593:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2078.716307] Lustre: 112593:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 24 previous similar messages [ 2079.689888] Lustre: *** cfs_fail_loc=1618, val=0*** [ 2079.695173] Lustre: Skipped 5 previous similar messages [ 2111.457551] 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 [ 2111.457808] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2111.465472] Lustre: Skipped 1 previous similar message [ 2116.575869] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2116.578412] Lustre: Skipped 6 previous similar messages [ 2117.706714] Lustre: server umount lustre-MDT0000 complete [ 2119.602294] LustreError: 110018:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788777166 with bad export cookie 17956790467230014007 [ 2119.603434] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2119.609623] LustreError: 110018:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2119.736199] Lustre: server umount lustre-MDT0001 complete [ 2131.921726] Lustre: server umount lustre-OST0000 complete [ 2143.981470] Lustre: server umount lustre-OST0001 complete [ 2151.156246] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 2156.063353] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2156.282343] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2158.273363] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2161.632593] LustreError: 118691:0:(ldlm_lib.c:1190: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. [ 2161.641049] LustreError: 118691:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 2 previous similar messages [ 2162.143087] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2164.051306] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2165.423120] Lustre: 119830:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2168.279382] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2168.416290] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 2168.418793] Lustre: Skipped 1 previous similar message [ 2171.188546] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2172.512842] LustreError: 120184:0:(ldlm_lib.c:1190: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. [ 2172.515422] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:33) [ 2174.840919] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2177.375791] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2180.067538] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:33) [ 2181.092466] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:116 to 0x280000401:161) [ 2181.092697] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:33) [ 2186.545253] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2188.110360] Lustre: 121699:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2193.667399] Lustre: DEBUG MARKER: == sanity-lfsck test 18e: Find out orphan OST-object and repair it (5) ========================================================== 06:34:00 (1788777240) [ 2193.809163] Lustre: 121464:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 252 < left 278, rollback = 2 [ 2193.813431] Lustre: 121464:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 2193.816089] Lustre: 121464:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2193.819370] Lustre: 121464:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2193.822866] Lustre: 121464:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2193.826259] Lustre: 121464:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2193.829747] Lustre: 121464:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/1 [ 2193.833534] Lustre: 121464:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2193.836653] Lustre: 121464:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/3, delete: 0/0/0 [ 2193.839627] Lustre: 121464:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2193.843022] Lustre: 121464:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2193.845542] Lustre: 121464:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2194.608305] Lustre: *** cfs_fail_loc=1618, val=0*** [ 2194.611104] Lustre: Skipped 3 previous similar messages [ 2227.167980] 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 [ 2227.168935] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2227.172700] Lustre: Skipped 5 previous similar messages [ 2227.175665] Lustre: Skipped 2 previous similar messages [ 2232.176194] Lustre: server umount lustre-MDT0000 complete [ 2232.287933] LustreError: 118691:0:(ldlm_lib.c:1190: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. [ 2232.294614] LustreError: 118691:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 2233.627912] LustreError: 119832:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788777280 with bad export cookie 17956790467230029246 [ 2233.629329] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2233.634260] LustreError: 119832:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 1 previous similar message [ 2233.754306] Lustre: server umount lustre-MDT0001 complete [ 2245.640661] Lustre: server umount lustre-OST0000 complete [ 2257.924420] Lustre: server umount lustre-OST0001 complete [ 2265.796489] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 2270.805299] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2271.027396] LustreError: 124264:0:(ldlm_lib.c:1190: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. [ 2271.067567] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2271.072039] Lustre: Skipped 1 previous similar message [ 2273.068436] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2276.319501] LustreError: 124265:0:(ldlm_lib.c:1190: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. [ 2277.557362] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2279.691535] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2281.099476] Lustre: 125402:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2284.386953] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2287.317292] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2287.650755] LustreError: 125756:0:(ldlm_lib.c:1190: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. [ 2287.656032] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:4 to 0x280000400:65) [ 2291.260319] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2294.047395] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2296.486561] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:166 to 0x280000401:193) [ 2296.494108] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:3 to 0x2c0000400:65) [ 2296.494221] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:4 to 0x2c0000401:65) [ 2303.428533] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2305.093417] Lustre: 127274:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/lod.*.mdt_hash=crush (mode = 0) failed: rc = -17 [ 2307.585420] Lustre: 124265:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-OST0000: opcode 2: before 252 < left 260, rollback = 2 [ 2307.591877] Lustre: 124265:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 21 previous similar messages [ 2307.598227] Lustre: 124265:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2307.605054] Lustre: 124265:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2307.609848] Lustre: 124265:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 1/260/0 [ 2307.613125] Lustre: 124265:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2307.616220] Lustre: 124265:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/9/0, punch: 0/0/0, quota 4/150/2 [ 2307.619521] Lustre: 124265:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2307.623271] Lustre: 124265:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 1/17/2, delete: 0/0/0 [ 2307.627571] Lustre: 124265:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2307.632124] Lustre: 124265:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2307.635641] Lustre: 124265:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 21 previous similar messages [ 2307.653912] Lustre: *** cfs_fail_loc=1602, val=10*** [ 2324.208289] Lustre: DEBUG MARKER: == sanity-lfsck test 18f: Skip the failed OST(s) when handle orphan OST-objects ========================================================== 06:36:11 (1788777371) [ 2325.592627] Lustre: *** cfs_fail_loc=1616, val=0*** [ 2325.595135] Lustre: Skipped 3 previous similar messages [ 2329.617777] Lustre: *** cfs_fail_loc=161c, val=0*** [ 2337.303158] Lustre: DEBUG MARKER: == sanity-lfsck test 18g: Find out orphan OST-object and repair it (7) ========================================================== 06:36:24 (1788777384) [ 2338.137833] Lustre: *** cfs_fail_loc=162e, val=0*** [ 2343.414309] Lustre: DEBUG MARKER: == sanity-lfsck test 18h: LFSCK can repair crashed PFL extent range ========================================================== 06:36:30 (1788777390) [ 2345.676073] Lustre: *** cfs_fail_loc=162f, val=0*** [ 2345.680215] Lustre: Skipped 9 previous similar messages [ 2354.231350] Lustre: DEBUG MARKER: == sanity-lfsck test 19a: OST-object inconsistency self detect ========================================================== 06:36:41 (1788777401) [ 2361.363151] Lustre: DEBUG MARKER: == sanity-lfsck test 19b: OST-object inconsistency self repair ========================================================== 06:36:48 (1788777408) [ 2362.919761] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2362.939752] Lustre: *** cfs_fail_loc=1611, val=0*** [ 2362.941489] Lustre: Skipped 3 previous similar messages [ 2365.916237] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.15@tcp inode [0x2000013a1:0x1f:0x0] object 0x280000401:203 extent [0-4095], client returned csum 0 (type 4), server csum 703fb3ad (type 4) [ 2367.003989] LustreError: lustre-OST0000: BAD READ CHECKSUM: should have changed on the client or in transit: from 192.168.206.15@tcp inode [0x2000013a1:0x20:0x0] object 0x280000401:204 extent [0-4095], client returned csum 0 (type 4), server csum 7cbb935c (type 4) [ 2370.111987] Lustre: DEBUG MARKER: == sanity-lfsck test 20a: Handle the orphan with dummy LOV EA slot properly ========================================================== 06:36:57 (1788777417) [ 2403.635659] Lustre: 131896:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 253 < left 263, rollback = 2 [ 2403.643150] Lustre: 131896:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 125 previous similar messages [ 2403.646781] Lustre: 131896:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/4, destroy: 0/0/0 [ 2403.650522] Lustre: 131896:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 2403.653889] Lustre: 131896:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 0/0/0, xattr_set: 2/263/0 [ 2403.658056] Lustre: 131896:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 2403.661271] Lustre: 131896:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 1/3/2 [ 2403.665367] Lustre: 131896:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 2403.668558] Lustre: 131896:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/33/1, delete: 0/0/0 [ 2403.672305] Lustre: 131896:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 2403.676268] Lustre: 131896:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 0/0/0, ref_del: 0/0/0 [ 2403.679664] Lustre: 131896:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 125 previous similar messages [ 2409.428471] Lustre: DEBUG MARKER: == sanity-lfsck test 20b: Handle the orphan with dummy LOV EA slot properly - PFL case ========================================================== 06:37:36 (1788777456) [ 2411.978187] Lustre: DEBUG MARKER: == sanity-lfsck test 21: run all LFSCK components by default ========================================================== 06:37:39 (1788777459) [ 2417.267306] Lustre: DEBUG MARKER: == sanity-lfsck test 22a: LFSCK can repair unmatched pairs (1) ========================================================== 06:37:44 (1788777464) [ 2418.317268] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2418.320185] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2418.322657] Lustre: Skipped 1 previous similar message [ 2422.693786] Lustre: DEBUG MARKER: == sanity-lfsck test 22b: LFSCK can repair unmatched pairs (2) ========================================================== 06:37:49 (1788777469) [ 2423.359665] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2423.361473] Lustre: *** cfs_fail_loc=161e, val=0*** [ 2428.149559] Lustre: DEBUG MARKER: == sanity-lfsck test 23a: LFSCK can repair dangling name entry (1) ========================================================== 06:37:55 (1788777475) [ 2428.860714] Lustre: *** cfs_fail_loc=1620, val=0*** [ 2434.598955] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_23b skipping excluded test 23b [ 2435.295540] Lustre: DEBUG MARKER: == sanity-lfsck test 23c: LFSCK can repair dangling name entry (3) ========================================================== 06:38:02 (1788777482) [ 2437.624859] Lustre: *** cfs_fail_loc=1621, val=127*** [ 2437.626928] Lustre: Skipped 1 previous similar message [ 2438.783189] Lustre: *** cfs_fail_loc=1602, val=10*** [ 2452.441828] Lustre: DEBUG MARKER: == sanity-lfsck test 23d: LFSCK can repair a dangling name entry to a remote object ========================================================== 06:38:19 (1788777499) [ 2453.284355] Lustre: Failing over lustre-MDT0000 [ 2453.513390] Lustre: server umount lustre-MDT0000 complete [ 2455.520690] 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 [ 2455.521401] LustreError: 124259:0:(ldlm_lib.c:1190: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. [ 2455.526592] Lustre: Skipped 2 previous similar messages [ 2455.536836] LustreError: 124259:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 3 previous similar messages [ 2457.212201] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2457.272728] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2457.371391] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2457.374954] Lustre: Skipped 3 previous similar messages [ 2457.390601] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2459.034536] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2462.299761] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2462.689519] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2462.701445] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2462.711766] LustreError: 124260:0:(mdt_open.c:1324:mdt_cross_open()) lustre-MDT0000: [0x2000013a3:0x82:0x0] doesn't exist!: rc = -14 [ 2462.718865] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:265 to 0x280000401:289) [ 2462.718947] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:130 to 0x2c0000401:161) [ 2466.695333] Lustre: DEBUG MARKER: == sanity-lfsck test 24: LFSCK can repair multiple-referenced name entry ========================================================== 06:38:33 (1788777513) [ 2467.425277] Lustre: *** cfs_fail_loc=1622, val=0*** [ 2467.464671] Lustre: *** cfs_fail_loc=1622, val=0*** [ 2467.467591] Lustre: Skipped 1 previous similar message [ 2471.642435] Lustre: DEBUG MARKER: == sanity-lfsck test 25: LFSCK can repair bad file type in the name entry ========================================================== 06:38:38 (1788777518) [ 2472.250080] Lustre: *** cfs_fail_loc=1623, val=0*** [ 2476.689658] Lustre: DEBUG MARKER: == sanity-lfsck test 26a: LFSCK can add the missing local name entry back to the namespace ========================================================== 06:38:43 (1788777523) [ 2477.434412] Lustre: *** cfs_fail_loc=1624, val=0*** [ 2481.985326] Lustre: DEBUG MARKER: == sanity-lfsck test 26b: LFSCK can add the missing remote name entry back to the namespace ========================================================== 06:38:49 (1788777529) [ 2487.125933] Lustre: DEBUG MARKER: == sanity-lfsck test 27a: LFSCK can recreate the lost local parent directory as orphan ========================================================== 06:38:54 (1788777534) [ 2491.959443] Lustre: DEBUG MARKER: == sanity-lfsck test 27b: LFSCK can recreate the lost remote parent directory as orphan ========================================================== 06:38:59 (1788777539) [ 2496.629545] Lustre: DEBUG MARKER: == sanity-lfsck test 28: Skip the failed MDT(s) when handle orphan MDT-objects ========================================================== 06:39:03 (1788777543) [ 2497.634656] Lustre: *** cfs_fail_loc=1624, val=0*** [ 2497.636976] Lustre: Skipped 4 previous similar messages [ 2499.037461] Lustre: *** cfs_fail_loc=161c, val=0*** [ 2499.039568] Lustre: Skipped 3 previous similar messages [ 2504.875698] Lustre: DEBUG MARKER: == sanity-lfsck test 29b: LFSCK can repair bad nlink count (2) ========================================================== 06:39:12 (1788777552) [ 2510.025225] Lustre: DEBUG MARKER: == sanity-lfsck test 29c: verify linkEA size limitation == 06:39:17 (1788777557) [ 2522.906346] Lustre: DEBUG MARKER: == sanity-lfsck test 29d: accessing non-existing inode shouldn't turn fs read-only (ldiskfs) ========================================================== 06:39:30 (1788777570) [ 2523.960663] LustreError: 126149:0:(osd_handler.c:284:osd_idc_find_or_init()) lustre-MDT0000: cannot lookup FID [0x2000013a3:0x9e:0x0]: rc = -2 [ 2526.445413] Lustre: DEBUG MARKER: == sanity-lfsck test 30: LFSCK can recover the orphans from backend /lost+found ========================================================== 06:39:33 (1788777573) [ 2558.155209] Lustre: Failing over lustre-MDT0000 [ 2558.337204] Lustre: server umount lustre-MDT0000 complete [ 2559.967972] 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 [ 2559.968327] LustreError: 124265:0:(ldlm_lib.c:1190: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. [ 2559.972878] Lustre: Skipped 4 previous similar messages [ 2559.973046] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2559.978112] LustreError: 124265:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 4 previous similar messages [ 2562.698429] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2562.765436] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2562.862696] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 2562.877673] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2564.641076] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2565.826890] Lustre: 143089:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 259 < left 264, rollback = 2 [ 2565.831237] Lustre: 143089:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 778 previous similar messages [ 2565.834677] Lustre: 143089:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 0/0/0, destroy: 0/0/0 [ 2565.840359] Lustre: 143089:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 778 previous similar messages [ 2565.844396] Lustre: 143089:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 2/264/0 [ 2565.849493] Lustre: 143089:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 778 previous similar messages [ 2565.852285] Lustre: 143089:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 0/0/0, punch: 0/0/0, quota 1/3/0 [ 2565.856269] Lustre: 143089:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 778 previous similar messages [ 2565.860242] Lustre: 143089:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 2/32/1, delete: 1/1/0 [ 2565.864529] Lustre: 143089:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 778 previous similar messages [ 2565.867179] Lustre: 143089:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 1/1/0, ref_del: 0/0/0 [ 2565.870322] Lustre: 143089:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 778 previous similar messages [ 2568.162114] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2568.163794] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2568.168330] Lustre: Skipped 3 previous similar messages [ 2568.177754] Lustre: lustre-MDT0000: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2568.196940] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:321) [ 2568.197267] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:193) [ 2572.671260] Lustre: DEBUG MARKER: == sanity-lfsck test 31a: The LFSCK can find/repair the name entry with bad name hash (1) ========================================================== 06:40:19 (1788777619) [ 2577.776323] Lustre: DEBUG MARKER: == sanity-lfsck test 31b: The LFSCK can find/repair the name entry with bad name hash (2) ========================================================== 06:40:25 (1788777625) [ 2582.940101] Lustre: DEBUG MARKER: == sanity-lfsck test 31c: Re-generate the lost master LMV EA for striped directory ========================================================== 06:40:30 (1788777630) [ 2583.489631] Lustre: *** cfs_fail_loc=1629, val=0*** [ 2583.491182] Lustre: Skipped 7 previous similar messages [ 2588.185830] Lustre: DEBUG MARKER: == sanity-lfsck test 31d: Set broken striped directory (modified after broken) as read-only ========================================================== 06:40:35 (1788777635) [ 2590.327759] Lustre: Failing over lustre-MDT0000 [ 2593.760594] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2593.761683] 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 [ 2593.762392] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2593.775387] Lustre: Skipped 3 previous similar messages [ 2595.906619] Lustre: server umount lustre-MDT0000 complete [ 2599.551793] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2599.611800] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2599.729665] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2601.409748] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2602.280503] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2602.284792] Lustre: lustre-MDT0000: Denying connection for new client d5a54f1d-c535-4fb6-bd5a-d8faa8b78923 (at 192.168.206.15@tcp), waiting for 1 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 1:00 [ 2605.025852] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2605.029780] Lustre: Skipped 3 previous similar messages [ 2605.042583] Lustre: lustre-MDT0000: Recovery over after 0:03, of 1 clients 1 recovered and 0 were evicted. [ 2605.060944] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:353) [ 2605.060944] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:167 to 0x2c0000401:225) [ 2611.465704] Lustre: Failing over lustre-MDT0000 [ 2611.695778] Lustre: server umount lustre-MDT0000 complete [ 2615.263859] 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 [ 2615.265817] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2615.270821] Lustre: Skipped 2 previous similar messages [ 2615.390879] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2615.474222] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2615.589572] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 2617.345742] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2617.947914] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2620.903033] Lustre: lustre-MDT0000-lwp-MDT0001: Connection restored to 0@lo (at 0@lo) [ 2620.905656] Lustre: Skipped 3 previous similar messages [ 2620.915642] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 2620.932766] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:227 to 0x2c0000401:257) [ 2620.932772] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:294 to 0x280000401:385) [ 2623.687769] Lustre: DEBUG MARKER: == sanity-lfsck test 31e: Re-generate the lost slave LMV EA for striped directory (1) ========================================================== 06:41:10 (1788777670) [ 2628.635136] Lustre: DEBUG MARKER: == sanity-lfsck test 31f: Re-generate the lost slave LMV EA for striped directory (2) ========================================================== 06:41:15 (1788777675) [ 2633.550428] Lustre: DEBUG MARKER: == sanity-lfsck test 31g: Repair the corrupted slave LMV EA ========================================================== 06:41:20 (1788777680) [ 2667.741564] Lustre: DEBUG MARKER: == sanity-lfsck test 31h: Repair the corrupted shard's name entry ========================================================== 06:41:54 (1788777714) [ 2668.374993] Lustre: *** cfs_fail_loc=162c, val=0*** [ 2668.376915] Lustre: Skipped 13 previous similar messages [ 2673.508287] Lustre: DEBUG MARKER: == sanity-lfsck test 32a: stop LFSCK when some OST failed ========================================================== 06:42:00 (1788777720) [ 2676.625398] LustreError: 148943:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2677.689315] Lustre: Failing over lustre-OST0000 [ 2677.745110] Lustre: server umount lustre-OST0000 complete [ 2678.919258] LustreError: 148943:0:(lfsck_layout.c:4529:lfsck_layout_assistant_handler_p1()) cfs_fail_timeout interrupted [ 2678.931386] LustreError: lustre-OST0000-osc-MDT0000: operation lfsck_notify to node 0@lo failed: rc = -107 [ 2678.936873] 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 [ 2678.945984] LustreError: 126150:0:(ldlm_lib.c:1190: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. [ 2678.955285] LustreError: 126150:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 9 previous similar messages [ 2686.033876] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2686.118894] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 2687.329529] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2687.340218] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2687.340309] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 0@lo (at 0@lo) [ 2687.347689] Lustre: Skipped 3 previous similar messages [ 2688.498743] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2691.904759] Lustre: DEBUG MARKER: == sanity-lfsck test 32b: stop LFSCK when some MDT failed ========================================================== 06:42:19 (1788777739) [ 2697.742239] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 2704.821782] Lustre: 151740:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2714.381472] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2720.073028] LustreError: 152993:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2720.078027] LustreError: 152993:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) Skipped 1 previous similar message [ 2721.126876] Lustre: Failing over lustre-MDT0001 [ 2722.272572] 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 [ 2722.273216] Lustre: lustre-MDT0001: Not available for connect from 0@lo (stopping) [ 2722.276786] Lustre: Skipped 3 previous similar messages [ 2722.279018] Lustre: Skipped 4 previous similar messages [ 2723.095168] LustreError: 152992:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d awake [ 2723.099571] LustreError: 152992:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout id 162d sleeping for 3000ms [ 2723.205085] Lustre: server umount lustre-MDT0001 complete [ 2724.351066] LustreError: 152992:0:(lfsck_striped_dir.c:1762:lfsck_namespace_verify_stripe_slave()) cfs_fail_timeout interrupted [ 2731.595598] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,user_xattr,no_mbcache,nodelalloc [ 2731.732322] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 2731.734697] Lustre: Skipped 3 previous similar messages [ 2731.746302] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2733.471569] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2737.122355] Lustre: lustre-MDT0001: Will be in recovery for at least 1:00, or until 1 client reconnects [ 2737.124416] Lustre: lustre-MDT0001-lwp-OST0001: Connection restored to 0@lo (at 0@lo) [ 2737.133150] Lustre: Skipped 1 previous similar message [ 2737.143276] Lustre: lustre-MDT0001: Recovery over after 0:01, of 1 clients 1 recovered and 0 were evicted. [ 2737.172109] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:97) [ 2737.173509] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:97) [ 2737.409349] Lustre: DEBUG MARKER: == sanity-lfsck test 33: check LFSCK paramters =========== 06:43:04 (1788777784) [ 2743.699712] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 2751.618122] Lustre: 155706:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2751.622263] Lustre: 155706:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2760.684445] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2769.765800] Lustre: DEBUG MARKER: == sanity-lfsck test 34: LFSCK can rebuild the lost agent object ========================================================== 06:43:36 (1788777816) [ 2770.373929] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_34 Only valid for ZFS backend [ 2771.069275] Lustre: DEBUG MARKER: == sanity-lfsck test 35: LFSCK can rebuild the lost agent entry ========================================================== 06:43:38 (1788777818) [ 2773.841496] Lustre: *** cfs_fail_loc=1631, val=0*** [ 2783.200363] LustreError: lustre-MDT0000-osp-MDT0001: operation mds_statfs to node 0@lo failed: rc = -107 [ 2783.200573] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 2783.204593] LustreError: Skipped 1 previous similar message [ 2783.207578] Lustre: Skipped 4 previous similar messages [ 2786.020795] Lustre: server umount lustre-MDT0000 complete [ 2787.501260] LustreError: 124244:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788777834 with bad export cookie 17956790467230101927 [ 2787.503331] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2787.506325] LustreError: 124244:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 2787.648642] Lustre: server umount lustre-MDT0001 complete [ 2799.629096] Lustre: server umount lustre-OST0000 complete [ 2811.619382] Lustre: server umount lustre-OST0001 complete [ 2818.181757] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 2822.952584] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2823.147267] LustreError: 159584:0:(ldlm_lib.c:1190: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. [ 2823.152048] LustreError: 159584:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 6 previous similar messages [ 2825.172067] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2829.997724] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2833.091380] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2834.760586] Lustre: 160724:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify general/debug_raw_pointers=Y (mode = 0) failed: rc = -17 [ 2834.766585] Lustre: 160724:0:(mgs_llog.c:1450:mgs_modify_param()) Skipped 1 previous similar message [ 2838.212666] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2840.422491] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:70 to 0x280000400:129) [ 2841.208762] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2845.409195] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 2847.788526] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2848.610747] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:540 to 0x280000401:577) [ 2848.611148] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:129) [ 2848.634767] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:412 to 0x2c0000401:449) [ 2851.089929] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 2856.058263] Lustre: DEBUG MARKER: == sanity-lfsck test 36a: rebuild LOV EA for mirrored file (1) ========================================================== 06:45:03 (1788777903) [ 2856.664643] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36a needs >= 3 OSTs [ 2857.394860] Lustre: DEBUG MARKER: == sanity-lfsck test 36b: rebuild LOV EA for mirrored file (2) ========================================================== 06:45:04 (1788777904) [ 2858.023104] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36b needs >= 3 OSTs [ 2858.761363] Lustre: DEBUG MARKER: == sanity-lfsck test 36c: rebuild LOV EA for mirrored file (3) ========================================================== 06:45:05 (1788777905) [ 2859.360626] Lustre: DEBUG MARKER: SKIP: sanity-lfsck test_36c needs >= 3 OSTs [ 2860.003334] Lustre: DEBUG MARKER: == sanity-lfsck test 37: LFSCK must skip a ORPHAN ======== 06:45:07 (1788777907) [ 2860.459821] Lustre: 159579:0:(osd_internal.h:1460:osd_trans_exec_op()) lustre-MDT0000: opcode 2: before 258 < left 278, rollback = 2 [ 2860.464709] Lustre: 159579:0:(osd_internal.h:1460:osd_trans_exec_op()) Skipped 1602 previous similar messages [ 2860.468975] Lustre: 159579:0:(osd_handler.c:2090:osd_trans_dump_creds()) create: 1/4/0, destroy: 0/0/0 [ 2860.472371] Lustre: 159579:0:(osd_handler.c:2090:osd_trans_dump_creds()) Skipped 1602 previous similar messages [ 2860.476279] Lustre: 159579:0:(osd_handler.c:2097:osd_trans_dump_creds()) attr_set: 1/1/0, xattr_set: 4/278/0 [ 2860.479925] Lustre: 159579:0:(osd_handler.c:2097:osd_trans_dump_creds()) Skipped 1602 previous similar messages [ 2860.483451] Lustre: 159579:0:(osd_handler.c:2107:osd_trans_dump_creds()) write: 1/11/0, punch: 0/0/0, quota 1/3/0 [ 2860.486988] Lustre: 159579:0:(osd_handler.c:2107:osd_trans_dump_creds()) Skipped 1602 previous similar messages [ 2860.490961] Lustre: 159579:0:(osd_handler.c:2114:osd_trans_dump_creds()) insert: 4/65/2, delete: 0/0/0 [ 2860.494421] Lustre: 159579:0:(osd_handler.c:2114:osd_trans_dump_creds()) Skipped 1602 previous similar messages [ 2860.498280] Lustre: 159579:0:(osd_handler.c:2121:osd_trans_dump_creds()) ref_add: 2/2/0, ref_del: 0/0/0 [ 2860.501837] Lustre: 159579:0:(osd_handler.c:2121:osd_trans_dump_creds()) Skipped 1602 previous similar messages [ 2864.072846] Lustre: DEBUG MARKER: == sanity-lfsck test 38: LFSCK does not break foreign file and reverse is also true ========================================================== 06:45:11 (1788777911) [ 2870.243142] Lustre: DEBUG MARKER: == sanity-lfsck test 39: LFSCK does not break foreign dir and reverse is also true ========================================================== 06:45:17 (1788777917) [ 2875.757048] Lustre: DEBUG MARKER: == sanity-lfsck test 40a: LFSCK correctly fixes lmm_oi in composite layout ========================================================== 06:45:23 (1788777923) [ 2881.498124] Lustre: DEBUG MARKER: == sanity-lfsck test 41: SEL support in LFSCK ============ 06:45:28 (1788777928) [ 2919.875462] Lustre: DEBUG MARKER: == sanity-lfsck test 42: LFSCK repairs inconsistent MDT-object/OST-object encryption flags ========================================================== 06:46:07 (1788777967) [ 2951.531403] Lustre: *** cfs_fail_loc=1632, val=0*** [ 2957.101698] Lustre: DEBUG MARKER: == sanity-lfsck test 43: LFSCK does not loop endlessly on iget failure in scanning-phase1 ========================================================== 06:46:44 (1788778004) [ 2958.176265] Lustre: Failing over lustre-MDT0001 [ 2960.997373] Lustre: lustre-MDT0001: Not available for connect from 192.168.206.15@tcp (stopping) [ 2961.376182] 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 [ 2961.376215] LustreError: lustre-MDT0001-osp-MDT0000: operation mds_statfs to node 0@lo failed: rc = -107 [ 2961.382020] Lustre: Skipped 6 previous similar messages [ 2964.023790] Lustre: server umount lustre-MDT0001 complete [ 2966.882920] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2967.055309] Lustre: lustre-MDT0001: in recovery but waiting for the first client to connect [ 2967.055584] Lustre: lustre-MDT0001: Aborting client recovery [ 2967.060058] LustreError: 167527:0:(ldlm_lib.c:3029:target_stop_recovery_thread()) lustre-MDT0001: Aborting recovery [ 2967.063215] Lustre: 167551:0:(ldlm_lib.c:2429:target_recovery_overseer()) recovery is aborted, evict exports in recovery [ 2967.066228] Lustre: 167551:0:(genops.c:1601:class_disconnect_stale_exports()) lustre-MDT0001: disconnect stale client 58dd3d94-6473-4ad2-8485-3f7c010a3ac1@ [ 2967.070471] Lustre: lustre-MDT0001: disconnecting 2 stale clients [ 2967.073672] Lustre: lustre-MDT0001-osd: cancel update llog [0x240000400:0x1:0x0] [ 2967.078876] Lustre: lustre-MDT0000-osp-MDT0001: cancel update llog [0x200000401:0x1:0x0] [ 2967.099660] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:69 to 0x2c0000400:161) [ 2967.099771] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:131 to 0x280000400:161) [ 2968.665902] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2970.029822] Lustre: *** cfs_fail_loc=1e2, val=483*** [ 2971.570395] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing wait_import_state FULL osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid [ 2972.128192] LustreError: lustre-MDT0001-osp-MDT0000: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 2972.136132] Lustre: lustre-MDT0001-lwp-OST0000: Connection restored to 0@lo (at 0@lo) [ 2972.138812] Lustre: Skipped 3 previous similar messages [ 2972.731551] Lustre: DEBUG MARKER: osp.lustre-MDT0001-os[pc]-MDT0000.*_server_uuid in FULL state after 1 sec [ 2975.212552] Lustre: DEBUG MARKER: == sanity-lfsck test 44: umount while lfsck is stopping == 06:47:02 (1788778022) [ 2978.176589] Lustre: *** cfs_fail_loc=1600, val=3*** [ 2979.954520] Lustre: Failing over lustre-MDT0000 [ 2980.302802] Lustre: server umount lustre-MDT0000 complete [ 2980.833179] LustreError: 159565:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788778027 with bad export cookie 17956790467230174769 [ 2980.838040] LustreError: 159565:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 5 previous similar messages [ 2984.055834] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 2984.112463] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 2985.833608] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 2986.589526] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 2989.281567] Lustre: DEBUG MARKER: == sanity-lfsck test 45: LFSCK should fix UID/GID/PROJID of OST object ========================================================== 06:47:16 (1788778036) [ 2989.544437] Lustre: lustre-MDT0000: Recovery over after 0:03, of 2 clients 2 recovered and 0 were evicted. [ 2989.563676] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000401:621 to 0x280000401:641) [ 2989.563744] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000401:489 to 0x2c0000401:513) [ 3015.152905] Lustre: Failing over lustre-OST0000 [ 3015.197726] Lustre: server umount lustre-OST0000 complete [ 3017.665692] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null) [ 3018.208296] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 3022.282383] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3022.366297] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3022.370309] Lustre: Skipped 6 previous similar messages [ 3022.374796] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 3022.377354] Lustre: Skipped 3 previous similar messages [ 3022.427605] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 3023.397765] Lustre: lustre-OST0000: Recovery over after 0:01, of 3 clients 3 recovered and 0 were evicted. [ 3023.398178] Lustre: lustre-OST0000-osc-MDT0001: Connection restored to 0@lo (at 0@lo) [ 3023.404218] Lustre: Skipped 5 previous similar messages [ 3024.858874] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3027.438408] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid 50 [ 3027.545183] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0000.ost_server_uuid in FULL state after 0 sec [ 3029.356617] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing wait_import_state (FULL|IDLE) os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid 50 [ 3029.448221] Lustre: DEBUG MARKER: os[cp].lustre-OST0000-osc-MDT0001.ost_server_uuid in FULL state after 0 sec [ 3031.939634] Lustre: DEBUG MARKER: oleg615-client.virtnet: executing wait_import_state (FULL|IDLE) osc.lustre-OST0000-osc-ffffa0e5c3131800.ost_server_uuid 50 [ 3032.561516] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-ffffa0e5c3131800.ost_server_uuid in FULL state after 0 sec [ 3083.744172] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3083.746712] Lustre: Skipped 6 previous similar messages [ 3088.655802] Lustre: server umount lustre-MDT0000 complete [ 3088.863391] LustreError: 166581:0:(ldlm_lib.c:1190: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. [ 3088.867324] LustreError: 166581:0:(ldlm_lib.c:1190:target_handle_connect()) Skipped 19 previous similar messages [ 3091.508862] LustreError: 162594:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788778138 with bad export cookie 17956790467230184877 [ 3091.510553] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3091.512101] LustreError: 162594:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 4 previous similar messages [ 3091.610228] Lustre: server umount lustre-MDT0001 complete [ 3104.132542] Lustre: server umount lustre-OST0000 complete [ 3117.649651] Lustre: server umount lustre-OST0001 complete [ 3124.061967] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing unload_modules_local [ 3125.251451] Key type lgssc unregistered [ 3125.394160] LNet: 177394:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3125.397602] LNetError: 177394:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3125.412304] LNet: Removed LNI 192.168.206.115@tcp [ 3125.809145] Key type .llcrypt unregistered [ 3125.810846] Key type ._llcrypt unregistered [ 3137.230060] Key type ._llcrypt registered [ 3137.231405] Key type .llcrypt registered [ 3137.280570] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_hostid [ 3145.265503] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 3145.716816] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 1 [ 3145.741282] alg: No test for adler32 (adler32-zlib) [ 3146.611979] Lustre: Lustre: Build Version: 2.17.57_103_g80273de [ 3146.707326] LNet: Added LNI 192.168.206.115@tcp [8/256/0/180] [ 3148.303474] Key type lgssc registered [ 3148.740610] Lustre: Echo OBD driver; http://www.lustre.org/ [ 3168.884171] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing load_modules_local [ 3173.498632] Lustre: lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt' [ 3173.506616] LDISKFS-fs (dm-0): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3174.594115] Lustre: Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000 [ 3174.605817] Lustre: ctl-lustre-MDT0000: No data found on store. Initialize space. [ 3174.643951] Lustre: lustre-MDT0000: new disk, initializing [ 3174.667795] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 3174.675300] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 3176.187642] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3181.531280] LDISKFS-fs (dm-1): mounted filesystem with ordered data mode. Opts: user_xattr,errors=remount-ro,no_mbcache,nodelalloc [ 3181.569107] Lustre: 181812:0:(mgs_llog.c:1450:mgs_modify_param()) MGS: modify lustre-MDT0001/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity (mode = 0) failed: rc = -17 [ 3181.581645] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 3181.583232] Lustre: Skipped 1 previous similar message [ 3181.616252] Lustre: lustre-MDT0001: new disk, initializing [ 3181.635693] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 3181.644868] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 3181.648957] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 3183.151268] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3185.609344] Lustre: Modifying parameter general.debug_raw_pointers=Y in log params [ 3189.432757] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3189.522093] Lustre: lustre-OST0000: new disk, initializing [ 3189.524489] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 3189.527697] Lustre: 183752:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3189.549208] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 3190.192201] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 3190.196342] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 3190.223532] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 3191.740235] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3197.524545] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: errors=remount-ro,no_mbcache,nodelalloc [ 3197.571731] Lustre: lustre-OST0001: new disk, initializing [ 3197.573630] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 3197.576364] Lustre: 184781:0:(osd_compat.c:1353:osd_object_spec_find()) UNKNOWN COMPAT FID [0x200000001:0x101e:0x0] [ 3197.594945] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 3199.774983] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 3203.570515] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x00000002c0000400-0x0000000300000400]:1:ost [ 3203.575333] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x00000002c0000400-0x0000000300000400]:1:ost] [ 3203.597854] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 3205.745215] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 3207.629772] Lustre: Setting parameter general.lod.*.mdt_hash=crush in log params [ 3209.746279] Lustre: DEBUG MARKER: === sanity-lfsck: finish setup 06:50:56 (1788778256) === [ 3210.352131] Lustre: DEBUG MARKER: == sanity-lfsck test complete, duration 3063 sec ========= 06:50:57 (1788778257) [ 3210.933391] Lustre: DEBUG MARKER: === sanity-lfsck: start cleanup 06:50:58 (1788778258) === [ 3212.080066] Lustre: DEBUG MARKER: === sanity-lfsck: finish cleanup 06:50:59 (1788778259) === [ 3213.791630] 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 [ 3213.792496] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3213.796354] Lustre: Skipped 3 previous similar messages [ 3213.798854] Lustre: Skipped 2 previous similar messages [ 3218.911611] Lustre: lustre-MDT0000: Not available for connect from 0@lo (stopping) [ 3218.917115] Lustre: Skipped 4 previous similar messages [ 3219.230758] Lustre: server umount lustre-MDT0000 complete [ 3222.422080] LustreError: 181806:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) ldlm_cancel from 0@lo arrived at 1788778269 with bad export cookie 11026836524574366553 [ 3222.423319] LustreError: MGC192.168.206.115@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 3222.426741] LustreError: 181806:0:(ldlm_lockd.c:2564:ldlm_cancel_handler()) Skipped 3 previous similar messages [ 3222.551801] Lustre: server umount lustre-MDT0001 complete [ 3235.149717] Lustre: server umount lustre-OST0000 complete [ 3248.916448] Lustre: server umount lustre-OST0001 complete [ 3255.305307] Lustre: DEBUG MARKER: oleg615-server.virtnet: executing unload_modules_local [ 3256.520688] Key type lgssc unregistered [ 3256.662477] LNet: 188247:0:(lib-ptl.c:964:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [ 3256.666289] LNetError: 188247:0:(acceptor.c:252:lnet_acceptor_remove_socket()) Interface ens2 not found [ 3256.673336] LNet: Removed LNI 192.168.206.115@tcp [ 3257.018126] Key type .llcrypt unregistered [ 3257.019740] Key type ._llcrypt unregistered