1054706 – boot seabios more than 1 minute when boot qemu-kvm with cpus more than 30

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1054706 - boot seabios more than 1 minute when boot qemu-kvm with cpus more than 30

Summary: boot seabios more than 1 minute when boot qemu-kvm with cpus more than 30

Keywords:
Status:	CLOSED DUPLICATE of bug 1036457
Alias:	None
Product:	Red Hat Enterprise Linux 7
Classification:	Red Hat
Component:	qemu-kvm
Sub Component:
Version:	7.0
Hardware:	x86_64
OS:	Linux
Priority:	high
Severity:	medium
Target Milestone:	rc
Target Release:	---
Assignee:	Gerd Hoffmann
QA Contact:	Virtualization Bugs
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2014-01-17 10:19 UTC by Jun Li
Modified:	2014-03-17 11:58 UTC (History)
CC List:	13 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2014-03-17 11:58:58 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)
perf kvm report (39.41 KB, image/png) 2014-02-28 10:07 UTC, Gerd Hoffmann	no flags	Details
View All

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Red Hat Bugzilla	1036457	1	None	None	None	2021-01-20 06:05:38 UTC

Internal Links: 1036457

Description Jun Li 2014-01-17 10:19:17 UTC

Description of problem:
when boot qemu-kvm with cpus more than 30, it will take more than 1 minute to entry the seabios GUI.

command line just like:
# /usr/libexec/qemu-kvm -smp 30 -vnc :1 -monitor stdio
---

Version-Release number of selected component (if applicable):
3.10.0-65.el7.x86_64
qemu-kvm-1.5.3-37.el7.x86_64
Host cpu:
AMD Athlon(tm) Dual Core Processor 5400B

How reproducible:
100%

Steps to Reproduce:
1.
2.
3.

Actual results:
when set "-smp" with more than 30 cpus, entry to seabios GUI too slow.

Expected results:
entry to seabios GUI as normal.

Additional info:
BTW, most of other machines not hit this issue.
I also find another machine has this issue.
host cpu: 
Intel(R) Xeon(R) CPU E7- 8870  @ 2.40GHz

Comment 2 Gerd Hoffmann 2014-01-17 15:36:37 UTC

Doesn't reproduce locally (not surprising).

Please try this:

/usr/libexec/qemu-kvm -enable-kvm -smp 128 -vnc :1 \
  -chardev stdio,id=log -device isa-debugcon,iobase=0x402,chardev=log

Does it hang before or after seabios boot messages start showing up?
In case of the latter:  Where in the message log does it hang?

Comment 3 Jun Li 2014-01-20 04:32:53 UTC

(In reply to Gerd Hoffmann from comment #2)
> Doesn't reproduce locally (not surprising).
> 
> Please try this:
> 
> /usr/libexec/qemu-kvm -enable-kvm -smp 128 -vnc :1 \
>   -chardev stdio,id=log -device isa-debugcon,iobase=0x402,chardev=log
> 
> Does it hang before or after seabios boot messages start showing up?
> In case of the latter:  Where in the message log does it hang?

# /usr/libexec/qemu-kvm -enable-kvm -smp 128 -vnc :1 \
-chardev stdio,id=log -device isa-debugcon,iobase=0x402,chardev=log

Start bios (version seabios-1.7.2.2-10.el7)

------
Try as above, it hangs at "Start bios (version seabios-1.7.2.2-10.el7)".

Comment 11 Gerd Hoffmann 2014-02-03 13:36:18 UTC

 39,99%       qemu-kvm  [kernel.kallsyms]        [k] _raw_spin_lock                                ◆
  4,42%       qemu-kvm  [kernel.kallsyms]        [k] native_read_msr_safe                          ▒
  2,50%       qemu-kvm  [kernel.kallsyms]        [k] dequeue_task_fair                             ▒
  2,46%       qemu-kvm  [kernel.kallsyms]        [k] select_task_rq_fair                           ▒
  2,41%       qemu-kvm  [kernel.kallsyms]        [k] update_curr                                   ▒
  2,23%       qemu-kvm  [kernel.kallsyms]        [k] _raw_spin_lock_irqsave                        ▒
  2,16%       qemu-kvm  [kernel.kallsyms]        [k] native_write_msr_safe                         ▒
  2,12%       qemu-kvm  [kernel.kallsyms]        [k] __schedule                                    ▒
  1,81%       qemu-kvm  [kvm]                    [k] kvm_arch_vcpu_load                            ▒
  1,78%       qemu-kvm  [kernel.kallsyms]        [k] enqueue_entity                                ▒
  1,73%       qemu-kvm  [kernel.kallsyms]        [k] perf_event_task_sched_out                     ▒
  1,72%       qemu-kvm  [kernel.kallsyms]        [k] enqueue_task_fair                             ▒
  1,53%       qemu-kvm  [kvm_amd]                [k] svm_interrupt_allowed                         ▒
  1,44%       qemu-kvm  [kvm]                    [k] kvm_sched_in                                  ▒
  1,43%       qemu-kvm  [kernel.kallsyms]        [k] dequeue_entity                                ▒
  1,34%       qemu-kvm  [kernel.kallsyms]        [k] try_to_wake_up                                ▒
  1,17%       qemu-kvm  [kernel.kallsyms]        [k] update_min_vruntime                           ▒
  1,15%       qemu-kvm  [kernel.kallsyms]        [k] sched_clock_local                             ▒
  1,14%       qemu-kvm  [kernel.kallsyms]        [k] task_waking_fair                              ▒
  1,07%       qemu-kvm  [kernel.kallsyms]        [k] schedule                                      ▒

Comment 12 Gerd Hoffmann 2014-02-03 13:40:09 UTC

So, it looks like lock contention on the host.
Can you repeat the test with call graphs (-g) enabled please, i.e. this:

perf kvm --host --guest  record -g -p `pidof qemu-kvm`

Comment 13 langfang 2014-02-07 03:06:33 UTC

(In reply to Gerd Hoffmann from comment #12)
> So, it looks like lock contention on the host.
> Can you repeat the test with call graphs (-g) enabled please, i.e. this:
> 
> perf kvm --host --guest  record -g -p `pidof qemu-kvm`

Hi,Gerd
   I can't download the build "http://brewweb.devel.redhat.com/brew/taskinfo?taskID=6895910 ", now the status is closed. could you help me ?

thanks

fang lang

Comment 14 Gerd Hoffmann 2014-02-17 08:16:00 UTC

kicked new scratch build:
http://brewweb.devel.redhat.com/brew/taskinfo?taskID=7063650

Comment 15 Jun Li 2014-02-18 06:57:47 UTC

(In reply to Gerd Hoffmann from comment #14)
> kicked new scratch build:
> http://brewweb.devel.redhat.com/brew/taskinfo?taskID=7063650

I am waiting for reserving that machine. thx.

Comment 16 Jun Li 2014-02-26 10:21:05 UTC

(In reply to Gerd Hoffmann from comment #14)
> kicked new scratch build:
> http://brewweb.devel.redhat.com/brew/taskinfo?taskID=7063650

Hi Gerd,
    Can not download the package from "http://brewweb.devel.redhat.com/brew/taskinfo?taskID=7063650".
    Could you help to check this url. thx.

Best Regards,
juli

Comment 17 Gerd Hoffmann 2014-02-26 10:56:21 UTC

kicked new scratch build:
https://brewweb.devel.redhat.com/taskinfo?taskID=7109560

Comment 18 Jun Li 2014-02-27 02:28:07 UTC

(In reply to Gerd Hoffmann from comment #17)
> kicked new scratch build:
> https://brewweb.devel.redhat.com/taskinfo?taskID=7109560

Retest with url:
https://brewweb.devel.redhat.com/taskinfo?taskID=7109560
-----
# /usr/libexec/qemu-kvm -enable-kvm -smp 128 -vnc :1 -chardev stdio,id=log -device isa-debugcon,iobase=0x402,chardev=log
Start bios (version seabios-1.7.2.2-10.el7.bz1054706.1)
handle_post:399
handle_post:403
handle_post:407
handle_post:411
...
------
# perf kvm --host --guest  record -g -p `pidof qemu-kvm`
-----------
The result file is:
perf.data.kvm-juli-20140227

You could download from url:
wget 10.66.7.190:8000/perf.data.kvm-juli-20140227

Comment 19 Gerd Hoffmann 2014-02-28 10:07:13 UTC

Created attachment 868940 [details]
perf kvm report

Hmm.  Alot of scheduling activity.  No obvious reason for that.

Quite some PMU activity, but I suspect this simply shows up here due to watching the qemu-kvm process with perf, not due to PMU emulation/passthrough.

Comment 20 Gerd Hoffmann 2014-02-28 10:27:03 UTC

Paolo, any clue what this might be?

Note this depends on host hardware somehow, shows on a few machines only,
but from both amd and intel camp ...

Comment 21 Andrew Jones 2014-02-28 10:55:21 UTC

(In reply to Gerd Hoffmann from comment #20)
> Paolo, any clue what this might be?
> 
> Note this depends on host hardware somehow, shows on a few machines only,
> but from both amd and intel camp ...

Does the host's dmesg say that the tsc has been marked as unstable?

Comment 22 Gerd Hoffmann 2014-02-28 12:38:04 UTC

Forwarding question to QE.  Jun, see comment 21, can you check the machines showing / not showing the issue?

Comment 23 Jun Li 2014-03-03 05:10:10 UTC

(In reply to Gerd Hoffmann from comment #22)
> Forwarding question to QE.  Jun, see comment 21, can you check the machines
> showing / not showing the issue?

Yes, dmesg say that the tsc has been marked as unstable.
# dmesg |grep -i tsc
[    0.000000] tsc: Fast TSC calibration using PIT
[    0.000000] tsc: Detected 2805.936 MHz processor
[    0.000000] tsc: Marking TSC unstable due to TSCs unsynchronized
-------------
# dmesg |grep -i tsc -n8
175-[    0.000000] NR_IRQS:327936 nr_irqs:712 16
176-[    0.000000] spurious 8259A interrupt: IRQ7.
177-[    0.000000] Console: colour VGA+ 80x25
178-[    0.000000] console [tty0] enabled
179-[    0.000000] console [ttyS0] enabled
180-[    0.000000] allocated 16777216 bytes of page_cgroup
181-[    0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups
182-[    0.000000] hpet clockevent registered
183:[    0.000000] tsc: Fast TSC calibration using PIT
184:[    0.000000] tsc: Detected 2805.936 MHz processor
185:[    0.000000] tsc: Marking TSC unstable due to TSCs unsynchronized
186-[    0.001005] Calibrating delay loop (skipped), value calculated using timer frequency.. 5611.87 BogoMIPS (lpj=2805936)
187-[    0.001009] pid_max: default: 32768 minimum: 301
188-[    0.001040] Security Framework initialized
189-[    0.001052] SELinux:  Initializing.
190-[    0.001062] SELinux:  Starting in permissive mode
191-[    0.002057] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
192-[    0.004323] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
193-[    0.005447] Mount-cache hash table entries: 256

Comment 24 Andrew Jones 2014-03-03 10:12:07 UTC

This is likely a dup of bug 1036457. I'm brewing a kernel that can be used to test a fix for that bug here

https://brewweb.devel.redhat.com/taskinfo?taskID=7131223

(assuming the build completes) then we can try it on these hosts to prove that this bug is a dup.

Comment 25 juzhang 2014-03-17 10:04:49 UTC

Also tested by using 160 vCPUs with fixed kernel.
'-smp 160,sockets=8,cores=10,threads=2'

Result:
Booting guest took about 30 sec.
# ./boot.sh 
start boot at:	03/17/14 05:46:00
finish boot at:	03/17/14 05:46:33

Viewed debuginfo from seabios console, shows below:
# nc -U /tmp/seabios 
Start bios (version seabios-1.7.2.2-12.el7)
Ram Size=0xc0000000 (0x0000000040000000 high)
Relocating low data from 0x000e3ec0 to 0x000ef780 (size 2161)
Relocating init from 0x000e4731 to 0xbffe2ce0 (size 53759)
CPU Mhz=1998
=== PCI bus & bridge init ===
PCI: pci_bios_init_bus_rec bus = 0x0
=== PCI device probing ===
Found 7 PCI devices (max PCI bus is 00)
=== PCI new allocation pass #1 ===
PCI: check devices
=== PCI new allocation pass #2 ===
PCI: IO: c000 - c08f
PCI: 32: 00000000c0000000 - 00000000fec00000
PCI: map device bdf=00:03.0  bar 0, addr 0000c000, size 00000040 [io]
PCI: map device bdf=00:02.0  bar 3, addr 0000c040, size 00000020 [io]
PCI: map device bdf=00:04.0  bar 0, addr 0000c060, size 00000020 [io]
PCI: map device bdf=00:01.1  bar 4, addr 0000c080, size 00000010 [io]
PCI: map device bdf=00:02.0  bar 0, addr f4000000, size 04000000 [mem]
PCI: map device bdf=00:02.0  bar 1, addr f8000000, size 04000000 [mem]
PCI: map device bdf=00:02.0  bar 6, addr fc000000, size 00010000 [mem]
PCI: map device bdf=00:02.0  bar 2, addr fc010000, size 00002000 [mem]
PCI: map device bdf=00:03.0  bar 1, addr fc012000, size 00001000 [mem]
PCI: map device bdf=00:04.0  bar 1, addr fc013000, size 00001000 [mem]
PCI: init bdf=00:00.0 id=8086:1237
PCI: init bdf=00:01.0 id=8086:7000
PIIX3/PIIX4 init: elcr=00 0c
PCI: init bdf=00:01.1 id=8086:7010
PCI: init bdf=00:01.3 id=8086:7113
Using pmtimer, ioport 0xb008, freq 3579 kHz
PCI: init bdf=00:02.0 id=1b36:0100
PCI: init bdf=00:03.0 id=1af4:1001
PCI: init bdf=00:04.0 id=1af4:1003
Found 160 cpu(s) max supported 244 cpu(s)
MP table addr=0x000fdec0 MPC table addr=0x000fded0 size=372
SMBIOS ptr=0x000fdea0 table=0xbfffd3d0 size=11297
Scan for VGA option rom
Running option rom at c000:0003
Start SeaVGABIOS (version seabios-1.7.2.2-12.el7)
enter vga_post:
   a=00000010  b=0000ffff  c=00000000  d=0000ffff ds=0000 es=f000 ss=0000
  si=00000000 di=0000d150 bp=00000000 sp=00006de2 cs=f000 ip=c4de  f=0000
VBE DISPI: bdf 00:02.0, bar 0
VBE DISPI: lfb_addr=f4000000, size 64 MB
Turning on vga text mode console
set VGA mode 3
SeaBIOS (version seabios-1.7.2.2-12.el7)
Machine UUID cca1433d-5bac-490f-a097-c5c80c1a083f
Found 0 lpt ports
Found 0 serial ports
ATA controller 1 at 1f0/3f4/0 (irq 14 dev 9)
ATA controller 2 at 170/374/0 (irq 15 dev 9)
found virtio-blk at 0:3
Searching bootorder for: /pci@i0cf8/*@3
PS2 keyboard initialized
All threads complete.
Scan for option roms
Searching bootorder for: /rom@genroms/kvmvapic.bin
Searching bootorder for: HALT
drive 0x000fde20: PCHS=16383/16/63 translation=lba LCHS=1024/255/63 s=83886080
Running option rom at c900:0003
Space available for UMB: 000cb800-000ed800
Returned 20480 bytes of ZoneHigh
e820 map has 8 items:
  0: 0000000000000000 - 000000000009fc00 = 1 RAM
  1: 000000000009fc00 - 00000000000a0000 = 2 RESERVED
  2: 00000000000f0000 - 0000000000100000 = 2 RESERVED
  3: 0000000000100000 - 00000000bfff5000 = 1 RAM
  4: 00000000bfff5000 - 00000000c0000000 = 2 RESERVED
  5: 00000000feffc000 - 00000000ff000000 = 2 RESERVED
  6: 00000000fffc0000 - 0000000100000000 = 2 RESERVED
  7: 0000000100000000 - 0000000140000000 = 1 RAM
enter handle_19:
  NULL
Booting from Hard Disk...
Booting from 0000:7c00
VBE mode info request: 100
VBE mode info request: 101
VBE mode info request: 102
VBE mode info request: 103
VBE mode info request: 104
VBE mode info request: 105
VBE mode info request: 106
VBE mode info request: 107
VBE mode info request: 10d
VBE mode info request: 10e
VBE mode info request: 10f
VBE mode info request: 110
VBE mode info request: 111
VBE mode info request: 112
VBE mode info request: 113
VBE mode info request: 114
VBE mode info request: 115
VBE mode info request: 116
VBE mode info request: 117
VBE mode info request: 118
VBE mode info request: 119
VBE mode info request: 11a
VBE mode info request: 11b
VBE mode info request: 11c
VBE mode info request: 11d
VBE mode info request: 11e
VBE mode info request: 11f
VBE mode info request: 140
VBE mode info request: 141
VBE mode info request: 142
VBE mode info request: 143
VBE mode info request: 144
VBE mode info request: 145
VBE mode info request: 146
VBE mode info request: 147
VBE mode info request: 148
VBE mode info request: 149
VBE mode info request: 14a
VBE mode info request: 14b
VBE mode info request: 14c
VBE mode info request: 178
VBE mode info request: 179
VBE mode info request: 17a
VBE mode info request: 17b
VBE mode info request: 17c
VBE mode info request: 17d
VBE mode info request: 17e
VBE mode info request: 17f
VBE mode info request: 180
VBE mode info request: 181
VBE mode info request: 182
VBE mode info request: 183
VBE mode info request: 184
VBE mode info request: 185
VBE mode info request: 186
VBE mode info request: 187
VBE mode info request: 188
VBE mode info request: 189
VBE mode info request: 18a
VBE mode info request: 18b
VBE mode info request: 18c
VBE mode info request: 0
VBE mode info request: 1
VBE mode info request: 2
VBE mode info request: 3
VBE mode info request: 4
VBE mode info request: 5
VBE mode info request: 6
VBE mode info request: 7
VBE mode info request: d
VBE mode info request: e
VBE mode info request: f
VBE mode info request: 10
VBE mode info request: 11
VBE mode info request: 12
VBE mode info request: 13
VBE mode info request: 6a
set VGA mode 3

Comment 26 Andrew Jones 2014-03-17 11:58:58 UTC

re: bug 1036457 comment 39, closing as dup of 1036457

*** This bug has been marked as a duplicate of bug 1036457 ***

Note You need to log in before you can comment on or make changes to this bug.