Bug 196901 - Failed to boot with ftrace=function in kvm with 2vcpu
Summary: Failed to boot with ftrace=function in kvm with 2vcpu
Status: RESOLVED CODE_FIX
Alias: None
Product: Tracing/Profiling
Classification: Unclassified
Component: Ftrace (show other bugs)
Hardware: All Linux
: P1 high
Assignee: Steven Rostedt
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-09-11 06:18 UTC by Ziqian SUN (Zamir)
Modified: 2019-05-22 13:05 UTC (History)
1 user (show)

See Also:
Kernel Version: 4.13.0-1.fc27.x86_64
Subsystem:
Regression: No
Bisected commit-id:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Description Ziqian SUN (Zamir) 2017-09-11 06:18:30 UTC 
Description:

When ftrace=function is in the kernel commandline on a kvm based 2vCPU VM, system cannot boot up.
At the end of the console log, it shows the following:

[    0.000000] Delta way too big! 18446743876904240054 ts=18446743876904240054 write stamp = 0
[    0.000000] If you just came from a suspend/resume,
[    0.000000] please switch to the trace global clock:
[    0.000000]   echo global > /sys/kernel/debug/tracing/trace_clock

Then system reboots. 

Versions:

I checked three kernel version of Fedora. This issue can be found in Fedora kernel 4.13.0-1.fc27.x86_64 and 4.12.9-300.fc26.x86_64.
However this issue did not happen in kernel 4.11.8-300.fc26.x86_64.

Steps to reproduce:
I find this might depends on machine. I believe it is simply boot with 'ftrace=function' into kernel parameter. I cannot reproduce on my laptop, but reproduced on a kvm based VM with 2vCPU. Console log following

[    0.000000] Linux version 4.12.9-300.fc26.x86_64 (mockbuild@bkernel02.phx2.fedoraproject.org) (gcc version 7.1.1 20170622 (Red Hat 7.1.1-3) (GCC) ) #1 SMP Fri Aug 25 13:09:43 UTC 2017
[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-4.12.9-300.fc26.x86_64 root=/dev/mapper/fedora-root ro rd.lvm.lv=fedora/root rd.lvm.lv=fedora/swap console=ttyS0 ftrace=function
[    0.000000] x86/fpu: x87 FPU will use FXSAVE
[    0.000000] e820: 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-0x000000003fffdfff] usable
[    0.000000] BIOS-e820: [mem 0x000000003fffe000-0x000000003fffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 2.4 present.
[    0.000000] DMI: Red Hat KVM, BIOS 0.5.1 01/01/2011
[    0.000000] Hypervisor detected: KVM
[    0.000000] tsc: Fast TSC calibration using PIT
[    0.000000] e820: last_pfn = 0x3fffe max_arch_pfn = 0x400000000
[    0.000000] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WC  UC- WT  
[    0.000000] found SMP MP-table at [mem 0x000f72b0-0x000f72bf] mapped at [ffff94ac000f72b0]
[    0.000000] RAMDISK: [mem 0x36320000-0x37187fff]
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F70E0 000014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 0x000000003FFFFB04 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 0x000000003FFFF177 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 0x000000003FFFE040 001137 (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACS 0x000000003FFFE000 000040
[    0.000000] ACPI: SSDT 0x000000003FFFF1EB 000899 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: APIC 0x000000003FFFFA84 000080 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000003fffdfff]
[    0.000000] NODE_DATA(0) allocated [mem 0x3ffd3000-0x3fffdfff]
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:3ff53001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 196805311562 cycles
[    0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   DMA32    [mem 0x0000000001000000-0x000000003fffdfff]
[    0.000000]   Normal   empty
[    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-0x000000003fffdfff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000003fffdfff]
[    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] smpboot: Allowing 2 CPUs, 0 hotplug CPUs
[    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] e820: [mem 0x40000000-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:2 nr_cpu_ids:2 nr_node_ids:1
[    0.000000] percpu: Embedded 37 pages/cpu @ffff94ac3fc00000 s112152 r8192 d31208 u1048576
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 3fc0d940
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 257927
[    0.000000] Policy zone: DMA32
[    0.000000] Kernel command line: BOOT_IMAGE=/vmlinuz-4.12.9-300.fc26.x86_64 root=/dev/mapper/fedora-root ro rd.lvm.lv=fedora/root rd.lvm.lv=fedora/swap console=ttyS0 ftrace=function
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] Memory: 994800K/1048176K available (8693K kernel code, 2456K rwdata, 3692K rodata, 2160K init, 1980K bss, 53376K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] ftrace: allocating 34424 entries in 135 pages
[    0.000000] Starting tracer 'function'
[    0.001000] Hierarchical RCU implementation.
[    0.001000] 	RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=2.
[    0.001000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.001000] NR_IRQS:524544 nr_irqs:440 16
[    0.001000] 	Offload RCU callbacks from all CPUs
[    0.001000] 	Offload RCU callbacks from CPUs: 0-1.
[    0.001000] Console: colour VGA+ 80x25
[    0.001000] console [ttyS0] enabled
[    0.001012] tsc: Detected 2792.998 MHz processor
[    0.001752] Calibrating delay loop (skipped) preset value.. 5585.99 BogoMIPS (lpj=2792998)
[    0.003010] pid_max: default: 32768 minimum: 301
[    0.003802] ACPI: Core revision 20170303
[    0.023385] ACPI: 2 ACPI AML tables successfully acquired and loaded
[    0.025627] Security Framework initialized
[    0.026020] Yama: becoming mindful.
[    0.027030] SELinux:  Initializing.
[    0.028586] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes)
[    0.030681] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes)
[    0.032341] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes)
[    0.033019] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes)
[    0.035714] mce: CPU supports 10 MCE banks
[    0.036068] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.037011] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.039286] Freeing SMP alternatives memory: 32K
[    0.044039] smpboot: Max logical packages: 2
[    0.045407] x2apic enabled
[    0.046022] Switched APIC routing to physical x2apic.
[    0.049504] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.050000] smpboot: CPU0: Intel Core i7 9xx (Nehalem Class Core i7) (family: 0x6, model: 0x1a, stepping: 0x3)
[    0.050475] Performance Events: unsupported p6 CPU model 26 no PMU driver, software events only.
[    0.053587] smp: Bringing up secondary CPUs ...
[    0.057146] x86: Booting SMP configuration:
[    0.058012] .... node  #0, CPUs:      #1
[    0.000000] Delta way too big! 18446743876904240054 ts=18446743876904240054 write stamp = 0
[    0.000000] If you just came from a suspend/resume,
[    0.000000] please switch to the trace global clock:
[    0.000000]   echo global > /sys/kernel/debug/tracing/trace_clock
Comment 1 Ziqian SUN (Zamir) 2017-10-11 08:14:45 UTC 
This still happen on 4.14.0-0.rc4.

[    0.000000] Linux version 4.14.0-0.rc4.git1.1.fc28.x86_64 (mockbuild@bkernel01.phx2.fedoraproject.org) (gcc version 7.2.1 20170829 (Red Hat 7.2.1-1) (GCC)) #1 SMP Tue Oct 10 17:01:29 UTC 2017
[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-4.14.0-0.rc4.git1.1.fc28.x86_64 root=/dev/mapper/fedora-root ro rd.lvm.lv=fedora/root rd.lvm.lv=fedora/swap LANG=en_US.UTF-8 console=tty0 console=ttyS0 ftrace=function
[    0.000000] x86/fpu: x87 FPU will use FXSAVE
[    0.000000] e820: 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-0x000000003fffdfff] usable
[    0.000000] BIOS-e820: [mem 0x000000003fffe000-0x000000003fffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] random: fast init done
[    0.000000] SMBIOS 2.4 present.
[    0.000000] DMI: Red Hat KVM, BIOS 0.5.1 01/01/2011
[    0.000000] Hypervisor detected: KVM
[    0.000000] tsc: Fast TSC calibration using PIT
[    0.000000] e820: last_pfn = 0x3fffe max_arch_pfn = 0x400000000
[    0.000000] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT  
[    0.000000] found SMP MP-table at [mem 0x000f72b0-0x000f72bf] mapped at [fffffffffd2002b0]
[    0.000000] Scanning 1 areas for low memory corruption
[    0.000000] RAMDISK: [mem 0x36439000-0x37214fff]
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F70E0 000014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 0x000000003FFFFB04 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 0x000000003FFFF177 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 0x000000003FFFE040 001137 (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACS 0x000000003FFFE000 000040
[    0.000000] ACPI: SSDT 0x000000003FFFF1EB 000899 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: APIC 0x000000003FFFFA84 000080 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000003fffdfff]
[    0.000000] NODE_DATA(0) allocated [mem 0x3ffd3000-0x3fffdfff]
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:3ff53001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 1626089434811 cycles
[    0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   DMA32    [mem 0x0000000001000000-0x000000003fffdfff]
[    0.000000]   Normal   empty
[    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-0x000000003fffdfff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000003fffdfff]
[    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] smpboot: Allowing 2 CPUs, 0 hotplug CPUs
[    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] e820: [mem 0x40000000-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:2 nr_cpu_ids:2 nr_node_ids:1
[    0.000000] percpu: Embedded 487 pages/cpu @ffff9fa3fe200000 s1954528 r8192 d32032 u2097152
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 3e20dc00
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 257927
[    0.000000] Policy zone: DMA32
[    0.000000] Kernel command line: BOOT_IMAGE=/vmlinuz-4.14.0-0.rc4.git1.1.fc28.x86_64 root=/dev/mapper/fedora-root ro rd.lvm.lv=fedora/root rd.lvm.lv=fedora/swap LANG=en_US.UTF-8 console=tty0 console=ttyS0 ftrace=function
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] Memory: 972972K/1048176K available (10095K kernel code, 3772K rwdata, 4076K rodata, 4736K init, 16852K bss, 75204K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] ftrace: allocating 35825 entries in 140 pages
[    0.000000] Starting tracer 'function'
[    0.001000] Running RCU self tests
[    0.001000] Hierarchical RCU implementation.
[    0.001000] 	RCU lockdep checking is enabled.
[    0.001000] 	RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=2.
[    0.001000] 	RCU callback double-/use-after-free debug enabled.
[    0.001000] 	Tasks RCU enabled.
[    0.001000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.001000] NR_IRQS: 524544, nr_irqs: 440, preallocated irqs: 16
[    0.001000] 	Offload RCU callbacks from CPUs: .
[    0.001000] Console: colour VGA+ 80x25
[    0.001000] console [tty0] enabled
[    0.001000] console [ttyS0] enabled
[    0.001000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    0.001000] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.001000] ... MAX_LOCK_DEPTH:          48
[    0.001000] ... MAX_LOCKDEP_KEYS:        8191
[    0.001000] ... CLASSHASH_SIZE:          4096
[    0.001000] ... MAX_LOCKDEP_ENTRIES:     32768
[    0.001000] ... MAX_LOCKDEP_CHAINS:      65536
[    0.001000] ... CHAINHASH_SIZE:          32768
[    0.001000]  memory used by lock dependency info: 7903 kB
[    0.001000]  per task-struct memory footprint: 3072 bytes
[    0.001000] kmemleak: Kernel memory leak detector disabled
[    0.001071] tsc: Detected 2792.998 MHz processor
[    0.002079] Calibrating delay loop (skipped) preset value.. 5585.99 BogoMIPS (lpj=2792998)
[    0.004051] pid_max: default: 32768 minimum: 301
[    0.007085] ACPI: Core revision 20170728
[    0.043917] ACPI: 2 ACPI AML tables successfully acquired and loaded
[    0.046707] Security Framework initialized
[    0.048077] Yama: becoming mindful.
[    0.049191] SELinux:  Initializing.
[    0.052787] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes)
[    0.055555] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes)
[    0.057362] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes)
[    0.059116] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes)
[    0.068754] mce: CPU supports 10 MCE banks
[    0.070196] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.071081] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.074605] Freeing SMP alternatives memory: 28K
[    0.082360] smpboot: Max logical packages: 2
[    0.084287] x2apic enabled
[    0.085056] Switched APIC routing to physical x2apic.
[    0.090000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.090000] smpboot: CPU0: Intel Core i7 9xx (Nehalem Class Core i7) (family: 0x6, model: 0x1a, stepping: 0x3)
[    0.095863] Performance Events: unsupported p6 CPU model 26 no PMU driver, software events only.
[    0.099535] Hierarchical SRCU implementation.
[    0.113582] NMI watchdog: Perf event create on CPU 0 failed with -2
[    0.114068] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.118699] smp: Bringing up secondary CPUs ...
[    0.140086] x86: Booting SMP configuration:
[    0.141069] .... node  #0, CPUs:      #1
[    0.000000] Delta way too big! 18446742447620116805 ts=18446742447620116805 write stamp = 0
[    0.000000] If you just came from a suspend/resume,
[    0.000000] please switch to the trace global clock:
[    0.000000]   echo global > /sys/kernel/debug/tracing/trace_clock
Comment 2 Ziqian SUN (Zamir) 2017-10-11 08:17:35 UTC 
I tried to add trace_clock=global when booting, and it can boot up, but another warning shows up which I believe is not a ftrace issue. For reference I paste it here as well.

[  102.395759] IPv6: ADDRCONF(NETDEV_UP): ens3: link is not ready
[  102.472428] 8139cp 0000:00:03.0 ens3: link up, 100Mbps, full-duplex, lpa 0x05E1
[  102.649028] WARNING: kernel stack regs at ffffaaf900603e88 in NetworkManager:545 has bad 'bp' value 00007fffef34a5d0
[  102.649037] unwind stack type:0 next_sp:          (null) mask:0x6 graph_idx:0
[  102.649045] ffff94cb7e203db0: ffff94cb7e203e40 (0xffff94cb7e203e40)
[  102.649055] ffff94cb7e203db8: ffffffff9b03db82 (__save_stack_trace+0x82/0x100)
[  102.649057] ffff94cb7e203dc0: 0000000000000000 ...
[  102.649060] ffff94cb7e203dc8: ffffaaf900600000 (0xffffaaf900600000)
[  102.649064] ffff94cb7e203dd0: ffffaaf900604000 (0xffffaaf900604000)
[  102.649066] ffff94cb7e203dd8: 0000000000000000 ...
[  102.649069] ffff94cb7e203de0: 0000000000000006 (0x6)
[  102.649073] ffff94cb7e203de8: ffff94cb7a923380 (0xffff94cb7a923380)
[  102.649077] ffff94cb7e203df0: 0000010100000000 (0x10100000000)
[  102.649079] ffff94cb7e203df8: 0000000000000000 ...
[  102.649083] ffff94cb7e203e00: ffff94cb7e203db0 (0xffff94cb7e203db0)
[  102.649086] ffff94cb7e203e08: ffffffffc00e4005 (0xffffffffc00e4005)
[  102.649089] ffff94cb7e203e10: ffffaaf900603e88 (0xffffaaf900603e88)
[  102.649093] ffff94cb7e203e18: 17f381169b5d6200 (0x17f381169b5d6200)
[  102.649098] ffff94cb7e203e20: ffff94cb7a9240d8 (0xffff94cb7a9240d8)
[  102.649111] ffff94cb7e203e28: ffffffff9cd9cc80 (chainhash_table+0xe320/0x40000)
[  102.649115] ffff94cb7e203e30: ffff94cb7a923380 (0xffff94cb7a923380)
[  102.649118] ffff94cb7e203e38: 45fb7ae5f3db03eb (0x45fb7ae5f3db03eb)
[  102.649122] ffff94cb7e203e40: ffff94cb7e203e50 (0xffff94cb7e203e50)
[  102.649127] ffff94cb7e203e48: ffffffff9b03dc1b (save_stack_trace+0x1b/0x20)
[  102.649131] ffff94cb7e203e50: ffff94cb7e203ed0 (0xffff94cb7e203ed0)
[  102.649139] ffff94cb7e203e58: ffffffff9b11bc73 (__lock_acquire+0xfb3/0x11d0)
[  102.649141] ffff94cb7e203e60: 0000000000000000 ...
[  102.649145] ffff94cb7e203e68: ffff94cb7e3d3028 (0xffff94cb7e3d3028)
[  102.649149] ffff94cb7e203e70: ffff94cb7e203e88 (0xffff94cb7e203e88)
[  102.649152] ffff94cb7e203e78: ffffffff00000001 (0xffffffff00000001)
[  102.649155] ffff94cb7e203e80: ffff94cb7a9240d8 (0xffff94cb7a9240d8)
[  102.649159] ffff94cb7e203e88: ffff94cb7e203f40 (0xffff94cb7e203f40)
[  102.649162] ffff94cb7e203e90: ffffffffc00e4077 (0xffffffffc00e4077)
[  102.649169] ffff94cb7e203e98: ffffffff9b1c49e8 (trace_function+0xa8/0xe0)
[  102.649173] ffff94cb7e203ea0: 17f381169b5d6200 (0x17f381169b5d6200)
[  102.649175] ffff94cb7e203ea8: 0000000000000000 ...
[  102.649178] ffff94cb7e203ec8: 0000000000000001 (0x1)
[  102.649182] ffff94cb7e203ed0: ffff94cb7e203f40 (0xffff94cb7e203f40)
[  102.649185] ffff94cb7e203ed8: ffffffff9b11c973 (lock_acquire+0xa3/0x1f0)
[  102.649188] ffff94cb7e203ee0: 0000000000000000 ...
[  102.649196] ffff94cb7e203ee8: ffffffff9b14de6e (hrtimer_interrupt+0x5e/0x210)
[  102.649198] ffff94cb7e203ef0: 0000000000000000 ...
[  102.649201] ffff94cb7e203f00: 00000000ffffffff (0xffffffff)
[  102.649205] ffff94cb7e203f08: ffff94cb7e3d2e58 (0xffff94cb7e3d2e58)
[  102.649208] ffff94cb7e203f10: 0000000000000046 (0x46)
[  102.649212] ffff94cb7e203f18: ffff94cb7e3d2e58 (0xffff94cb7e3d2e58)
[  102.649215] ffff94cb7e203f20: ffff94cb7e3d2e40 (0xffff94cb7e3d2e40)
[  102.649219] ffff94cb7e203f28: ffff94cb7e3d2e40 (0xffff94cb7e3d2e40)
[  102.649221] ffff94cb7e203f30: 0000000000000000 ...
[  102.649224] ffff94cb7e203f38: ffff94cb7e3d3028 (0xffff94cb7e3d3028)
[  102.649227] ffff94cb7e203f40: ffff94cb7e203f68 (0xffff94cb7e203f68)
[  102.649235] ffff94cb7e203f48: ffffffff9b9d55e4 (_raw_spin_lock+0x34/0x70)
[  102.649239] ffff94cb7e203f50: ffffffff9b14de6e (hrtimer_interrupt+0x5e/0x210)
[  102.649251] ffff94cb7e203f58: 7fffffffffffffff (0x7fffffffffffffff)
[  102.649254] ffff94cb7e203f60: 0000000000000003 (0x3)
[  102.649258] ffff94cb7e203f68: ffff94cb7e203fc8 (0xffff94cb7e203fc8)
[  102.649262] ffff94cb7e203f70: ffffffff9b14de6e (hrtimer_interrupt+0x5e/0x210)
[  102.649266] ffff94cb7e203f78: ffffffff9b14de15 (hrtimer_interrupt+0x5/0x210)
[  102.649268] ffff94cb7e203f80: 0000000000000000 ...
[  102.649272] ffff94cb7e203f90: 0000561f8f4cdd80 (0x561f8f4cdd80)
[  102.649276] ffff94cb7e203f98: ffff94cb7e203fb8 (0xffff94cb7e203fb8)
[  102.649280] ffff94cb7e203fa0: ffff94cb7e20d8c0 (0xffff94cb7e20d8c0)
[  102.649282] ffff94cb7e203fa8: 0000000000000000 ...
[  102.649286] ffff94cb7e203fc0: 0000561f8f4cdd80 (0x561f8f4cdd80)
[  102.649289] ffff94cb7e203fc8: ffff94cb7e203fe8 (0xffff94cb7e203fe8)
[  102.649295] ffff94cb7e203fd0: ffffffff9b9d9bc6 (smp_apic_timer_interrupt+0x76/0x2a0)
[  102.649299] ffff94cb7e203fd8: 0000561f90277800 (0x561f90277800)
[  102.649302] ffff94cb7e203fe0: 0000000000000221 (0x221)
[  102.649306] ffff94cb7e203fe8: ffffaaf900603e89 (0xffffaaf900603e89)
[  102.649309] ffff94cb7e203ff0: ffffffff9b9d80c7 (apic_timer_interrupt+0xa7/0xb0)
[  102.649313] ffff94cb7e203ff8: ffffaaf900603e88 (0xffffaaf900603e88)
[  102.649317] ffffaaf900603e88: 0000561f8f4cdd80 (0x561f8f4cdd80)
[  102.649319] ffffaaf900603e90: 0000000000000000 ...
[  102.649322] ffffaaf900603ea0: 0000000000000221 (0x221)
[  102.649326] ffffaaf900603ea8: 00007fffef34a5d0 (0x7fffef34a5d0)
[  102.649329] ffffaaf900603eb0: 0000561f90277800 (0x561f90277800)
[  102.649334] ffffaaf900603eb8: ffff94cb7a923380 (0xffff94cb7a923380)
[  102.649338] ffffaaf900603ec0: 0000561f90263100 (0x561f90263100)
[  102.649341] ffffaaf900603ec8: 0000561f90271f60 (0x561f90271f60)
[  102.649345] ffffaaf900603ed0: 0000000000000010 (0x10)
[  102.649348] ffffaaf900603ed8: 0000000000000027 (0x27)
[  102.649352] ffffaaf900603ee0: 0000561f90263100 (0x561f90263100)
[  102.649355] ffffaaf900603ee8: 0000000000000001 (0x1)
[  102.649357] ffffaaf900603ef0: 0000000000000000 ...
[  102.649360] ffffaaf900603ef8: 0000561f90277800 (0x561f90277800)
[  102.649364] ffffaaf900603f00: ffffffffffffff10 (0xffffffffffffff10)
[  102.649368] ffffaaf900603f08: ffffffffc00e4005 (0xffffffffc00e4005)
[  102.649371] ffffaaf900603f10: 0000000000000010 (0x10)
[  102.649374] ffffaaf900603f18: 0000000000000297 (0x297)
[  102.649378] ffffaaf900603f20: ffffaaf900603f38 (0xffffaaf900603f38)
[  102.649381] ffffaaf900603f28: 0000000000000018 (0x18)
[  102.649385] ffffaaf900603f30: 0000000000000001 (0x1)
[  102.649388] ffffaaf900603f38: ffffffff9b9d6241 (entry_SYSCALL_64_fastpath+0x1f/0xbe)
[  102.649392] ffffaaf900603f40: 00007fffef34a5d0 (0x7fffef34a5d0)
[  102.649400] ffffaaf900603f48: ffffffff9b0cdd55 (sys_getpid+0x5/0x30)
[  102.649404] ffffaaf900603f50: ffffffff9b9d6241 (entry_SYSCALL_64_fastpath+0x1f/0xbe)
[  102.649407] ffffaaf900603f58: 00000000901e8640 (0x901e8640)
[  102.649411] ffffaaf900603f60: 0000000000000007 (0x7)
[  102.649413] ffffaaf900603f68: 0000000000000000 ...
[  102.649416] ffffaaf900603f78: 0000000000000007 (0x7)
[  102.649420] ffffaaf900603f80: 0000561f90238460 (0x561f90238460)
[  102.649423] ffffaaf900603f88: 0000000000000206 (0x206)
[  102.649427] ffffaaf900603f90: 0000561f90263100 (0x561f90263100)
[  102.649430] ffffaaf900603f98: 0000561f90271f60 (0x561f90271f60)
[  102.649434] ffffaaf900603fa0: 0000000000000010 (0x10)
[  102.649437] ffffaaf900603fa8: ffffffffffffffda (0xffffffffffffffda)
[  102.649441] ffffaaf900603fb0: 00007f5307b902a7 (0x7f5307b902a7)
[  102.649444] ffffaaf900603fb8: 0000000000000001 (0x1)
[  102.649446] ffffaaf900603fc0: 0000000000000000 ...
[  102.649449] ffffaaf900603fc8: 0000561f90277800 (0x561f90277800)
[  102.649453] ffffaaf900603fd0: 0000000000000027 (0x27)
[  102.649456] ffffaaf900603fd8: 00007f5307b902a7 (0x7f5307b902a7)
[  102.649460] ffffaaf900603fe0: 0000000000000033 (0x33)
[  102.649463] ffffaaf900603fe8: 0000000000000206 (0x206)
[  102.649466] ffffaaf900603ff0: 00007fffef34a3b8 (0x7fffef34a3b8)
[  102.649469] ffffaaf900603ff8: 000000000000002b (0x2b)
Comment 3 Ziqian SUN (Zamir) 2017-10-11 08:19:46 UTC 
[root@f26 ~]# lscpu
Architecture:        x86_64
CPU op-mode(s):      32-bit, 64-bit
Byte Order:          Little Endian
CPU(s):              2
On-line CPU(s) list: 0,1
Thread(s) per core:  1
Core(s) per socket:  1
Socket(s):           2
NUMA node(s):        1
Vendor ID:           GenuineIntel
CPU family:          6
Model:               26
Model name:          Intel Core i7 9xx (Nehalem Class Core i7)
Stepping:            3
CPU MHz:             2792.998
BogoMIPS:            5585.99
Hypervisor vendor:   KVM
Virtualization type: full
L1d cache:           32K
L1i cache:           32K
L2 cache:            4096K
NUMA node0 CPU(s):   0,1
Flags:               fpu de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 syscall nx lm constant_tsc rep_good nopl cpuid pni ssse3 cx16 sse4_1 sse4_2 x2apic popcnt hypervisor lahf_lm
Comment 4 Steven Rostedt 2018-06-30 00:42:07 UTC 
Is this still an issue with the latest kernels?
Comment 5 Ziqian SUN (Zamir) 2018-07-02 12:28:43 UTC 
I haven't meet this issue for a long time. Will try again when I have some time and follow up here.
Comment 6 Ziqian SUN (Zamir) 2018-07-10 08:52:56 UTC 
Tried again on 4.16.2-300.fc28.x86_64 and this cannot be reproduced any longer.

You can close this bug with a proper resolution now. Thanks.

[root@localhost ~]# lscpu
Architecture:        x86_64
CPU op-mode(s):      32-bit, 64-bit
Byte Order:          Little Endian
CPU(s):              2
On-line CPU(s) list: 0,1
Thread(s) per core:  1
Core(s) per socket:  1
Socket(s):           2
NUMA node(s):        1
Vendor ID:           GenuineIntel
CPU family:          6
Model:               26
Model name:          Intel Core i7 9xx (Nehalem Class Core i7)
Stepping:            3
CPU MHz:             2793.544
BogoMIPS:            5587.08
Hypervisor vendor:   KVM
Virtualization type: full
L1d cache:           32K
L1i cache:           32K
L2 cache:            4096K
L3 cache:            16384K
NUMA node0 CPU(s):   0,1
Flags:               fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 syscall nx lm constant_tsc rep_good nopl xtopology cpuid pni ssse3 cx16 sse4_1 sse4_2 x2apic popcnt hypervisor lahf_lm cpuid_fault pti
[root@localhost ~]# cat /proc/cmdline 
BOOT_IMAGE=/vmlinuz-4.16.2-300.fc28.x86_64 root=/dev/mapper/fedora-root ro resume=/dev/mapper/fedora-swap rd.lvm.lv=fedora/root rd.lvm.lv=fedora/swap LANG=en_US.UTF-8 console=tty0 console=ttyS0 ftrace=function
[root@localhost ~]# cat /sys/kernel/debug/tracing/current_tracer 
function
Comment 7 Jerome Marchand 2018-11-06 17:27:46 UTC 
This has been fixed by:
commit 55d2d0ad2fb4 ("x86/idt: Load idt early in start_secondary")

At least the boot issue. The warning still remains.
Note You need to log in before you can comment on or make changes to this bug.