QEMU

QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase

Bug #1826393 reported by Waldemar Kozaczuk on 2019-04-25

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	QEMU	Fix Released	Undecided	Unassigned

Bug Description

Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and that way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have noticed that everytime I start QEMU to run OSv, QEMU seems to hand noticably longer (~1 second) before showing SeaBIOS output. I have tried all kind of combinations to get rid of that pause and nothing helped.

Here is my start command:
time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
-device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
-drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
-enable-kvm \
-cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
-mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio

It looks like qemu process starts, waits almost a second for something and then print SeaBIOS splashscreen and continues boot:

--> waits here
SeaBIOS (version 1.12.0-1)
Booting from Hard Disk..OSv v0.53.0-6-gc8395118
disk read (real mode): 27.25ms, (+27.25ms)
uncompress lzloader.elf: 46.22ms, (+18.97ms)
TLS initialization: 46.79ms, (+0.57ms)
.init functions: 47.82ms, (+1.03ms)
SMP launched: 48.08ms, (+0.26ms)
VFS initialized: 49.25ms, (+1.17ms)
Network initialized: 49.48ms, (+0.24ms)
pvpanic done: 49.57ms, (+0.08ms)
pci enumerated: 52.42ms, (+2.85ms)
drivers probe: 52.42ms, (+0.00ms)
drivers loaded: 55.33ms, (+2.90ms)
ROFS mounted: 56.37ms, (+1.04ms)
Total time: 56.37ms, (+0.00ms)
Found optarg
dev etc hello libenviron.so libvdso.so proc tmp tools usr

real 0m0.935s
user 0m0.426s
sys 0m0.490s

With version 2.12.0 I used to see real below 200ms. So it seems qemu slowed down 5 times.

I ran strace -tt against it and I have noticed a pause here:
...
07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
07:31:41.848649 ioctl(10, KVM_SET_PIT2, 0x7ffdd272d1f0) = 0
07:31:41.848674 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_KVMCLOCK_CTRL) = 1
07:31:41.848699 ioctl(10, KVM_SET_CLOCK, 0x7ffdd272d230) = 0
07:31:41.848724 futex(0x55c4a49a9a9c, FUTEX_WAKE_PRIVATE, 2147483647) = 1
07:31:41.848747 getpid() = 5162
07:31:41.848769 tgkill(5162, 5166, SIGUSR1) = 0
07:31:41.848791 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
07:31:41.848814 futex(0x55c4a49a9a98, FUTEX_WAKE_PRIVATE, 2147483647) = 1
07:31:41.848837 getpid() = 5162
07:31:41.848858 tgkill(5162, 5166, SIGUSR1) = 0
07:31:41.848889 write(8, "\1\0\0\0\0\0\0\0", 8) = 8
07:31:41.848919 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
07:31:41.848943 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
{fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=0}, NULL, 8) = 1 ([{fd=8, revents=POLLIN}], left {tv_sec=0, tv_nsec=0
})
07:31:41.849003 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
07:31:41.849031 read(8, "\5\0\0\0\0\0\0\0", 16) = 8
07:31:41.849064 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
07:31:41.849086 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
{fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=984624000}, NULL, 8) = 1 ([{fd=7, revents=POLLIN}], left {tv_sec=0, t
v_nsec=190532609})

--> waits for almost 800ms

07:31:42.643272 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
07:31:42.643522 read(7, "\1\0\0\0\0\0\0\0", 512) = 8
07:31:42.643625 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
07:31:42.643646 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
{fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=190066000}, NULL, 8) = 2 ([{fd=4, revents=POLLIN}, {fd=8, revents=POL
LIN}], left {tv_sec=0, tv_nsec=189909632})
07:31:42.643836 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
07:31:42.643859 read(8, "\2\0\0\0\0\0\0\0", 16) = 8
07:31:42.643880 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1

...

when I run same command using qemu 3.0.5 that I still happen to have on the same machine that I built directly from source I see total boot time at around 200ms. It seems like a regression.

Revision history for this message

Stefan Hajnoczi (stefanha) wrote on 2019-04-29: Re: [Qemu-devel] [Bug 1826393] [NEW] QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase

Download full text (9.3 KiB)

On Thu, Apr 25, 2019 at 11:37:02AM -0000, Waldemar Kozaczuk wrote:
> Public bug reported:
>
> Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and that
> way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have noticed
> that everytime I start QEMU to run OSv, QEMU seems to hand noticably
> longer (~1 second) before showing SeaBIOS output. I have tried all kind
> of combinations to get rid of that pause and nothing helped.
>
> Here is my start command:
> time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
> -device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
> -drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
> -enable-kvm \
> -cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
> -mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio
>
> It looks like qemu process starts, waits almost a second for something
> and then print SeaBIOS splashscreen and continues boot:
>
> --> waits here
> SeaBIOS (version 1.12.0-1)
> Booting from Hard Disk..OSv v0.53.0-6-gc8395118
> disk read (real mode): 27.25ms, (+27.25ms)
> uncompress lzloader.elf: 46.22ms, (+18.97ms)
> TLS initialization: 46.79ms, (+0.57ms)
> .init functions: 47.82ms, (+1.03ms)
> SMP launched: 48.08ms, (+0.26ms)
> VFS initialized: 49.25ms, (+1.17ms)
> Network initialized: 49.48ms, (+0.24ms)
> pvpanic done: 49.57ms, (+0.08ms)
> pci enumerated: 52.42ms, (+2.85ms)
> drivers probe: 52.42ms, (+0.00ms)
> drivers loaded: 55.33ms, (+2.90ms)
> ROFS mounted: 56.37ms, (+1.04ms)
> Total time: 56.37ms, (+0.00ms)
> Found optarg
> dev etc hello libenviron.so libvdso.so proc tmp tools usr
>
> real 0m0.935s
> user 0m0.426s
> sys 0m0.490s
>
> With version 2.12.0 I used to see real below 200ms. So it seems qemu
> slowed down 5 times.
>
> I ran strace -tt against it and I have noticed a pause here:
> ...
> 07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> 07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
> 07:31:41.848649 ioctl(10, KVM_SET_PIT2, 0x7ffdd272d1f0) = 0
> 07:31:41.848674 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_KVMCLOCK_CTRL) = 1
> 07:31:41.848699 ioctl(10, KVM_SET_CLOCK, 0x7ffdd272d230) = 0
> 07:31:41.848724 futex(0x55c4a49a9a9c, FUTEX_WAKE_PRIVATE, 2147483647) = 1
> 07:31:41.848747 getpid() = 5162
> 07:31:41.848769 tgkill(5162, 5166, SIGUSR1) = 0
> 07:31:41.848791 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> 07:31:41.848814 futex(0x55c4a49a9a98, FUTEX_WAKE_PRIVATE, 2147483647) = 1
> 07:31:41.848837 getpid() = 5162
> 07:31:41.848858 tgkill(5162, 5166, SIGUSR1) = 0
> 07:31:41.848889 write(8, "\1\0\0\0\0\0\0\0", 8) = 8
> 07:31:41.848919 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> 07:31:41.848943 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
> {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=0}, NULL, 8) = 1 ([{fd=8, revents=POLLIN}], left {tv_sec=0, tv_nsec=0
> })
> 07:31:41.849003 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
> 07:31:41.849031 read(8, "\5\0\0\0\0\0\0\0", 16) = 8
> 07:31:41.849064 futex(0x55c4a2fd34c0, FUTEX...

On Thu, Apr 25, 2019 at 11:37:02AM -0000, Waldemar Kozaczuk wrote:
> Public bug reported:
> 
> Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and that
> way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have noticed
> that everytime I start QEMU to run OSv, QEMU seems to hand noticably
> longer (~1 second) before showing SeaBIOS output. I have tried all kind
> of combinations to get rid of that pause and nothing helped.
> 
> Here is my start command:
> time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
>  -device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
>  -drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
>  -enable-kvm \
>  -cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
>  -mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio
> 
> It looks like qemu process starts, waits almost a second for something
> and then print SeaBIOS splashscreen and continues boot:
> 
> --> waits here
> SeaBIOS (version 1.12.0-1)
> Booting from Hard Disk..OSv v0.53.0-6-gc8395118
> 	disk read (real mode): 27.25ms, (+27.25ms)
> 	uncompress lzloader.elf: 46.22ms, (+18.97ms)
> 	TLS initialization: 46.79ms, (+0.57ms)
> 	.init functions: 47.82ms, (+1.03ms)
> 	SMP launched: 48.08ms, (+0.26ms)
> 	VFS initialized: 49.25ms, (+1.17ms)
> 	Network initialized: 49.48ms, (+0.24ms)
> 	pvpanic done: 49.57ms, (+0.08ms)
> 	pci enumerated: 52.42ms, (+2.85ms)
> 	drivers probe: 52.42ms, (+0.00ms)
> 	drivers loaded: 55.33ms, (+2.90ms)
> 	ROFS mounted: 56.37ms, (+1.04ms)
> 	Total time: 56.37ms, (+0.00ms)
> Found optarg
> dev  etc  hello  libenviron.so	libvdso.so  proc  tmp  tools  usr
> 
> real	0m0.935s
> user	0m0.426s
> sys	0m0.490s
> 
> With version 2.12.0 I used to see real below 200ms. So it seems qemu
> slowed down 5 times.
> 
> I ran strace -tt against it and I have noticed a pause here:
> ...
> 07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> 07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
> 07:31:41.848649 ioctl(10, KVM_SET_PIT2, 0x7ffdd272d1f0) = 0
> 07:31:41.848674 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_KVMCLOCK_CTRL) = 1
> 07:31:41.848699 ioctl(10, KVM_SET_CLOCK, 0x7ffdd272d230) = 0
> 07:31:41.848724 futex(0x55c4a49a9a9c, FUTEX_WAKE_PRIVATE, 2147483647) = 1
> 07:31:41.848747 getpid()                = 5162
> 07:31:41.848769 tgkill(5162, 5166, SIGUSR1) = 0
> 07:31:41.848791 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> 07:31:41.848814 futex(0x55c4a49a9a98, FUTEX_WAKE_PRIVATE, 2147483647) = 1
> 07:31:41.848837 getpid()                = 5162
> 07:31:41.848858 tgkill(5162, 5166, SIGUSR1) = 0
> 07:31:41.848889 write(8, "\1\0\0\0\0\0\0\0", 8) = 8
> 07:31:41.848919 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> 07:31:41.848943 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
> {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=0}, NULL, 8) = 1 ([{fd=8, revents=POLLIN}], left {tv_sec=0, tv_nsec=0
> })
> 07:31:41.849003 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
> 07:31:41.849031 read(8, "\5\0\0\0\0\0\0\0", 16) = 8
> 07:31:41.849064 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> 07:31:41.849086 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
> {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=984624000}, NULL, 8) = 1 ([{fd=7, revents=POLLIN}], left {tv_sec=0, t
> v_nsec=190532609})
> 
> --> waits for almost 800ms
> 
> 07:31:42.643272 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
> 07:31:42.643522 read(7, "\1\0\0\0\0\0\0\0", 512) = 8
> 07:31:42.643625 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> 07:31:42.643646 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
> {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=190066000}, NULL, 8) = 2 ([{fd=4, revents=POLLIN}, {fd=8, revents=POL
> LIN}], left {tv_sec=0, tv_nsec=189909632})
> 07:31:42.643836 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
> 07:31:42.643859 read(8, "\2\0\0\0\0\0\0\0", 16) = 8
> 07:31:42.643880 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> 
> ...
> 
> when I run same command using qemu 3.0.5 that I still happen to have on
> the same machine that I built directly from source I see total boot time
> at around 200ms. It seems like a regression.

Please try building QEMU 4.0.0 from source:

https://download.qemu.org/qemu-4.0.0.tar.xz

> ** Affects: qemu
>      Importance: Undecided
>          Status: New
> 
> -- 
> You received this bug notification because you are a member of qemu-
> devel-ml, which is subscribed to QEMU.
> https://bugs.launchpad.net/bugs/1826393
> 
> Title:
>   QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase
> 
> Status in QEMU:
>   New
> 
> Bug description:
>   Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and
>   that way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have
>   noticed that everytime I start QEMU to run OSv, QEMU seems to hand
>   noticably longer (~1 second) before showing SeaBIOS output. I have
>   tried all kind of combinations to get rid of that pause and nothing
>   helped.
> 
>   Here is my start command:
>   time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
>    -device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
>    -drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
>    -enable-kvm \
>    -cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
>    -mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio
> 
>   It looks like qemu process starts, waits almost a second for something
>   and then print SeaBIOS splashscreen and continues boot:
> 
>   --> waits here
>   SeaBIOS (version 1.12.0-1)
>   Booting from Hard Disk..OSv v0.53.0-6-gc8395118
>   	disk read (real mode): 27.25ms, (+27.25ms)
>   	uncompress lzloader.elf: 46.22ms, (+18.97ms)
>   	TLS initialization: 46.79ms, (+0.57ms)
>   	.init functions: 47.82ms, (+1.03ms)
>   	SMP launched: 48.08ms, (+0.26ms)
>   	VFS initialized: 49.25ms, (+1.17ms)
>   	Network initialized: 49.48ms, (+0.24ms)
>   	pvpanic done: 49.57ms, (+0.08ms)
>   	pci enumerated: 52.42ms, (+2.85ms)
>   	drivers probe: 52.42ms, (+0.00ms)
>   	drivers loaded: 55.33ms, (+2.90ms)
>   	ROFS mounted: 56.37ms, (+1.04ms)
>   	Total time: 56.37ms, (+0.00ms)
>   Found optarg
>   dev  etc  hello  libenviron.so	libvdso.so  proc  tmp  tools  usr
> 
>   real	0m0.935s
>   user	0m0.426s
>   sys	0m0.490s
> 
>   With version 2.12.0 I used to see real below 200ms. So it seems qemu
>   slowed down 5 times.
> 
>   I ran strace -tt against it and I have noticed a pause here:
>   ...
>   07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
>   07:31:41.848649 ioctl(10, KVM_SET_PIT2, 0x7ffdd272d1f0) = 0
>   07:31:41.848674 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_KVMCLOCK_CTRL) = 1
>   07:31:41.848699 ioctl(10, KVM_SET_CLOCK, 0x7ffdd272d230) = 0
>   07:31:41.848724 futex(0x55c4a49a9a9c, FUTEX_WAKE_PRIVATE, 2147483647) = 1
>   07:31:41.848747 getpid()                = 5162
>   07:31:41.848769 tgkill(5162, 5166, SIGUSR1) = 0
>   07:31:41.848791 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.848814 futex(0x55c4a49a9a98, FUTEX_WAKE_PRIVATE, 2147483647) = 1
>   07:31:41.848837 getpid()                = 5162
>   07:31:41.848858 tgkill(5162, 5166, SIGUSR1) = 0
>   07:31:41.848889 write(8, "\1\0\0\0\0\0\0\0", 8) = 8
>   07:31:41.848919 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
>   07:31:41.848943 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=0}, NULL, 8) = 1 ([{fd=8, revents=POLLIN}], left {tv_sec=0, tv_nsec=0
>   })
>   07:31:41.849003 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
>   07:31:41.849031 read(8, "\5\0\0\0\0\0\0\0", 16) = 8
>   07:31:41.849064 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.849086 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=984624000}, NULL, 8) = 1 ([{fd=7, revents=POLLIN}], left {tv_sec=0, t
>   v_nsec=190532609})
> 
>   --> waits for almost 800ms
> 
>   07:31:42.643272 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
>   07:31:42.643522 read(7, "\1\0\0\0\0\0\0\0", 512) = 8
>   07:31:42.643625 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
>   07:31:42.643646 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=190066000}, NULL, 8) = 2 ([{fd=4, revents=POLLIN}, {fd=8, revents=POL
>   LIN}], left {tv_sec=0, tv_nsec=189909632})
>   07:31:42.643836 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
>   07:31:42.643859 read(8, "\2\0\0\0\0\0\0\0", 16) = 8
>   07:31:42.643880 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> 
>   ...
> 
>   when I run same command using qemu 3.0.5 that I still happen to have
>   on the same machine that I built directly from source I see total boot
>   time at around 200ms. It seems like a regression.
> 
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/qemu/+bug/1826393/+subscriptions
>

Revision history for this message

Stefano Garzarella (sgarzare) wrote on 2019-04-29:

On Mon, Apr 29, 2019 at 11:47:33AM -0400, Stefan Hajnoczi wrote:
> On Thu, Apr 25, 2019 at 11:37:02AM -0000, Waldemar Kozaczuk wrote:
>
> Please try building QEMU 4.0.0 from source:
>
> https://download.qemu.org/qemu-4.0.0.tar.xz
>

It seems that is related to an issue with some TPM timeouts found in
SeaBIOS 1.12.0:
https://<email address hidden>/msg575060.html

As Stefan suggested the new QEMU 4.0.0 should not have this issue since
it is shipped with SeaBIOS 1.12.1 (where the fix is applied).

If you want to use QEMU 3.1.0 with the new SeaBIOS, you can download it
and use the '-bios' parameter:
$ wget https://github.com/qemu/qemu/blob/v4.0.0/pc-bios/bios-256k.bin
$ qemu-system-x86_64 -bios /path/to/bios-256k.bin ...

Revision history for this message

Waldemar Kozaczuk (wkozaczuk) wrote on 2019-05-01:

I tried with the bios https://github.com/qemu/qemu/blob/v4.0.0/pc-bios/bios-256k.bin and it failed like so:
```
qemu: could not load PC BIOS 'bios-256k.bin'
qemu failed.
```

Have not had chance to try with QEMU 4 yet.

Revision history for this message

Stefano Garzarella (sgarzare) wrote on 2019-05-02:

Oh sorry, you're using the 'pc' machine, so please try this bios: https://github.com/qemu/qemu/blob/v4.0.0/pc-bios/bios.bin

Revision history for this message

Waldemar Kozaczuk (wkozaczuk) wrote on 2019-05-06: Re: [Bug 1826393] Re: QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase

Download full text (5.3 KiB)

The last bios indeed helped. It knows runs under 200ms.

Do you anticipate doing minor release of 3.1.0 with updated bios to address
this issue? Or users are expected to upgrade to QEMU 4.0.0?

Regards,
Waldek

On Thu, May 2, 2019 at 4:05 AM Stefano Garzarella <
<email address hidden>> wrote:

The last bios indeed helped. It knows runs under 200ms.

Do you anticipate doing minor release of 3.1.0 with updated bios to address
this issue? Or users are expected to upgrade to QEMU 4.0.0?

Regards,
Waldek

On Thu, May 2, 2019 at 4:05 AM Stefano Garzarella <
1826393@bugs.launchpad.net> wrote:

> Oh sorry, you're using the 'pc' machine, so please try this bios:
> https://github.com/qemu/qemu/blob/v4.0.0/pc-bios/bios.bin
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1826393
>
> Title:
>   QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase
>
> Status in QEMU:
>   New
>
> Bug description:
>   Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and
>   that way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have
>   noticed that everytime I start QEMU to run OSv, QEMU seems to hand
>   noticably longer (~1 second) before showing SeaBIOS output. I have
>   tried all kind of combinations to get rid of that pause and nothing
>   helped.
>
>   Here is my start command:
>   time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
>    -device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
>    -drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
>    -enable-kvm \
>    -cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
>    -mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio
>
>   It looks like qemu process starts, waits almost a second for something
>   and then print SeaBIOS splashscreen and continues boot:
>
>   --> waits here
>   SeaBIOS (version 1.12.0-1)
>   Booting from Hard Disk..OSv v0.53.0-6-gc8395118
>         disk read (real mode): 27.25ms, (+27.25ms)
>         uncompress lzloader.elf: 46.22ms, (+18.97ms)
>         TLS initialization: 46.79ms, (+0.57ms)
>         .init functions: 47.82ms, (+1.03ms)
>         SMP launched: 48.08ms, (+0.26ms)
>         VFS initialized: 49.25ms, (+1.17ms)
>         Network initialized: 49.48ms, (+0.24ms)
>         pvpanic done: 49.57ms, (+0.08ms)
>         pci enumerated: 52.42ms, (+2.85ms)
>         drivers probe: 52.42ms, (+0.00ms)
>         drivers loaded: 55.33ms, (+2.90ms)
>         ROFS mounted: 56.37ms, (+1.04ms)
>         Total time: 56.37ms, (+0.00ms)
>   Found optarg
>   dev  etc  hello  libenviron.so        libvdso.so  proc  tmp  tools  usr
>
>   real  0m0.935s
>   user  0m0.426s
>   sys   0m0.490s
>
>   With version 2.12.0 I used to see real below 200ms. So it seems qemu
>   slowed down 5 times.
>
>   I ran strace -tt against it and I have noticed a pause here:
>   ...
>   07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
>   07:31:41.848649 ioctl(10, KVM_SET_PIT2, 0x7ffdd272d1f0) = 0
>   07:31:41.848674 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_KVMCLOCK_CTRL) = 1
>   07:31:41.848699 ioctl(10, KVM_SET_CLOCK, 0x7ffdd272d230) = 0
>   07:31:41.848724 futex(0x55c4a49a9a9c, FUTEX_WAKE_PRIVATE, 2147483647) = 1
>   07:31:41.848747 getpid()                = 5162
>   07:31:41.848769 tgkill(5162, 5166, SIGUSR1) = 0
>   07:31:41.848791 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.848814 futex(0x55c4a49a9a98, FUTEX_WAKE_PRIVATE, 2147483647) = 1
>   07:31:41.848837 getpid()                = 5162
>   07:31:41.848858 tgkill(5162, 5166, SIGUSR1) = 0
>   07:31:41.848889 write(8, "\1\0\0\0\0\0\0\0", 8) = 8
>   07:31:41.848919 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
>   07:31:41.848943 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN},
> {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=0}, NULL, 8) = 1 ([{fd=8,
> revents=POLLIN}], left {tv_sec=0, tv_nsec=0
>   })
>   07:31:41.849003 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1
> EAGAIN (Resource temporarily unavailable)
>   07:31:41.849031 read(8, "\5\0\0\0\0\0\0\0", 16) = 8
>   07:31:41.849064 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.849086 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN},
> {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=984624000}, NULL, 8) = 1
> ([{fd=7, revents=POLLIN}], left {tv_sec=0, t
>   v_nsec=190532609})
>
>   --> waits for almost 800ms
>
>   07:31:42.643272 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
>   07:31:42.643522 read(7, "\1\0\0\0\0\0\0\0", 512) = 8
>   07:31:42.643625 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
>   07:31:42.643646 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN},
> {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=190066000}, NULL, 8) = 2
> ([{fd=4, revents=POLLIN}, {fd=8, revents=POL
>   LIN}], left {tv_sec=0, tv_nsec=189909632})
>   07:31:42.643836 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1
> EAGAIN (Resource temporarily unavailable)
>   07:31:42.643859 read(8, "\2\0\0\0\0\0\0\0", 16) = 8
>   07:31:42.643880 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
>
>   ...
>
>   when I run same command using qemu 3.0.5 that I still happen to have
>   on the same machine that I built directly from source I see total boot
>   time at around 200ms. It seems like a regression.
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/qemu/+bug/1826393/+subscriptions
>

Revision history for this message

Stefano Garzarella (sgarzare) wrote on 2019-05-14:

Download full text (10.6 KiB)

On Mon, May 06, 2019 at 05:40:05PM -0000, Waldemar Kozaczuk wrote:
> The last bios indeed helped. It knows runs under 200ms.
>
> Do you anticipate doing minor release of 3.1.0 with updated bios to address
> this issue? Or users are expected to upgrade to QEMU 4.0.0?

CCing Gerd

I'm not sure we will release SeaBIOS 1.12.1 with a minor release of QEMU
3.1.0, so upgrading to QEMU 4.0 should be the way to address this issue.

Regards,
Stefano

>
> Regards,
> Waldek
>
> On Thu, May 2, 2019 at 4:05 AM Stefano Garzarella <
> <email address hidden>> wrote:
>
> > Oh sorry, you're using the 'pc' machine, so please try this bios:
> > https://github.com/qemu/qemu/blob/v4.0.0/pc-bios/bios.bin
> >
> > --
> > You received this bug notification because you are subscribed to the bug
> > report.
> > https://bugs.launchpad.net/bugs/1826393
> >
> > Title:
> > QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase
> >
> > Status in QEMU:
> > New
> >
> > Bug description:
> > Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and
> > that way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have
> > noticed that everytime I start QEMU to run OSv, QEMU seems to hand
> > noticably longer (~1 second) before showing SeaBIOS output. I have
> > tried all kind of combinations to get rid of that pause and nothing
> > helped.
> >
> > Here is my start command:
> > time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
> > -device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
> > -drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
> > -enable-kvm \
> > -cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
> > -mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio
> >
> > It looks like qemu process starts, waits almost a second for something
> > and then print SeaBIOS splashscreen and continues boot:
> >
> > --> waits here
> > SeaBIOS (version 1.12.0-1)
> > Booting from Hard Disk..OSv v0.53.0-6-gc8395118
> > disk read (real mode): 27.25ms, (+27.25ms)
> > uncompress lzloader.elf: 46.22ms, (+18.97ms)
> > TLS initialization: 46.79ms, (+0.57ms)
> > .init functions: 47.82ms, (+1.03ms)
> > SMP launched: 48.08ms, (+0.26ms)
> > VFS initialized: 49.25ms, (+1.17ms)
> > Network initialized: 49.48ms, (+0.24ms)
> > pvpanic done: 49.57ms, (+0.08ms)
> > pci enumerated: 52.42ms, (+2.85ms)
> > drivers probe: 52.42ms, (+0.00ms)
> > drivers loaded: 55.33ms, (+2.90ms)
> > ROFS mounted: 56.37ms, (+1.04ms)
> > Total time: 56.37ms, (+0.00ms)
> > Found optarg
> > dev etc hello libenviron.so libvdso.so proc tmp tools usr
> >
> > real 0m0.935s
> > user 0m0.426s
> > sys 0m0.490s
> >
> > With version 2.12.0 I used to see real below 200ms. So it seems qemu
> > slowed down 5 times.
> >
> > I ran strace -tt against it and I have noticed a pause here:
> > ...
> > 07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> > 07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
> > 07:31:41.848649 ioctl(10, KVM_SET_PIT...

On Mon, May 06, 2019 at 05:40:05PM -0000, Waldemar Kozaczuk wrote:
> The last bios indeed helped. It knows runs under 200ms.
> 
> Do you anticipate doing minor release of 3.1.0 with updated bios to address
> this issue? Or users are expected to upgrade to QEMU 4.0.0?

CCing Gerd

I'm not sure we will release SeaBIOS 1.12.1 with a minor release of QEMU
3.1.0, so upgrading to QEMU 4.0 should be the way to address this issue.

Regards,
Stefano

> 
> Regards,
> Waldek
> 
> On Thu, May 2, 2019 at 4:05 AM Stefano Garzarella <
> 1826393@bugs.launchpad.net> wrote:
> 
> > Oh sorry, you're using the 'pc' machine, so please try this bios:
> > https://github.com/qemu/qemu/blob/v4.0.0/pc-bios/bios.bin
> >
> > --
> > You received this bug notification because you are subscribed to the bug
> > report.
> > https://bugs.launchpad.net/bugs/1826393
> >
> > Title:
> >   QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase
> >
> > Status in QEMU:
> >   New
> >
> > Bug description:
> >   Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and
> >   that way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have
> >   noticed that everytime I start QEMU to run OSv, QEMU seems to hand
> >   noticably longer (~1 second) before showing SeaBIOS output. I have
> >   tried all kind of combinations to get rid of that pause and nothing
> >   helped.
> >
> >   Here is my start command:
> >   time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
> >    -device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
> >    -drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
> >    -enable-kvm \
> >    -cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
> >    -mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio
> >
> >   It looks like qemu process starts, waits almost a second for something
> >   and then print SeaBIOS splashscreen and continues boot:
> >
> >   --> waits here
> >   SeaBIOS (version 1.12.0-1)
> >   Booting from Hard Disk..OSv v0.53.0-6-gc8395118
> >         disk read (real mode): 27.25ms, (+27.25ms)
> >         uncompress lzloader.elf: 46.22ms, (+18.97ms)
> >         TLS initialization: 46.79ms, (+0.57ms)
> >         .init functions: 47.82ms, (+1.03ms)
> >         SMP launched: 48.08ms, (+0.26ms)
> >         VFS initialized: 49.25ms, (+1.17ms)
> >         Network initialized: 49.48ms, (+0.24ms)
> >         pvpanic done: 49.57ms, (+0.08ms)
> >         pci enumerated: 52.42ms, (+2.85ms)
> >         drivers probe: 52.42ms, (+0.00ms)
> >         drivers loaded: 55.33ms, (+2.90ms)
> >         ROFS mounted: 56.37ms, (+1.04ms)
> >         Total time: 56.37ms, (+0.00ms)
> >   Found optarg
> >   dev  etc  hello  libenviron.so        libvdso.so  proc  tmp  tools  usr
> >
> >   real  0m0.935s
> >   user  0m0.426s
> >   sys   0m0.490s
> >
> >   With version 2.12.0 I used to see real below 200ms. So it seems qemu
> >   slowed down 5 times.
> >
> >   I ran strace -tt against it and I have noticed a pause here:
> >   ...
> >   07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> >   07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
> >   07:31:41.848649 ioctl(10, KVM_SET_PIT2, 0x7ffdd272d1f0) = 0
> >   07:31:41.848674 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_KVMCLOCK_CTRL) = 1
> >   07:31:41.848699 ioctl(10, KVM_SET_CLOCK, 0x7ffdd272d230) = 0
> >   07:31:41.848724 futex(0x55c4a49a9a9c, FUTEX_WAKE_PRIVATE, 2147483647) = 1
> >   07:31:41.848747 getpid()                = 5162
> >   07:31:41.848769 tgkill(5162, 5166, SIGUSR1) = 0
> >   07:31:41.848791 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> >   07:31:41.848814 futex(0x55c4a49a9a98, FUTEX_WAKE_PRIVATE, 2147483647) = 1
> >   07:31:41.848837 getpid()                = 5162
> >   07:31:41.848858 tgkill(5162, 5166, SIGUSR1) = 0
> >   07:31:41.848889 write(8, "\1\0\0\0\0\0\0\0", 8) = 8
> >   07:31:41.848919 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> >   07:31:41.848943 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN},
> > {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
> >   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=0}, NULL, 8) = 1 ([{fd=8,
> > revents=POLLIN}], left {tv_sec=0, tv_nsec=0
> >   })
> >   07:31:41.849003 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1
> > EAGAIN (Resource temporarily unavailable)
> >   07:31:41.849031 read(8, "\5\0\0\0\0\0\0\0", 16) = 8
> >   07:31:41.849064 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
> >   07:31:41.849086 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN},
> > {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
> >   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=984624000}, NULL, 8) = 1
> > ([{fd=7, revents=POLLIN}], left {tv_sec=0, t
> >   v_nsec=190532609})
> >
> >   --> waits for almost 800ms
> >
> >   07:31:42.643272 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
> >   07:31:42.643522 read(7, "\1\0\0\0\0\0\0\0", 512) = 8
> >   07:31:42.643625 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> >   07:31:42.643646 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN},
> > {fd=5, events=POLLIN}, {fd=7, events=POLLIN},
> >   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=190066000}, NULL, 8) = 2
> > ([{fd=4, revents=POLLIN}, {fd=8, revents=POL
> >   LIN}], left {tv_sec=0, tv_nsec=189909632})
> >   07:31:42.643836 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1
> > EAGAIN (Resource temporarily unavailable)
> >   07:31:42.643859 read(8, "\2\0\0\0\0\0\0\0", 16) = 8
> >   07:31:42.643880 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> >
> >   ...
> >
> >   when I run same command using qemu 3.0.5 that I still happen to have
> >   on the same machine that I built directly from source I see total boot
> >   time at around 200ms. It seems like a regression.
> >
> > To manage notifications about this bug go to:
> > https://bugs.launchpad.net/qemu/+bug/1826393/+subscriptions
> >
> 
> -- 
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1826393
> 
> Title:
>   QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase
> 
> Status in QEMU:
>   New
> 
> Bug description:
>   Yesterday I have upgraded my laptop from Ubuntu 18.10 to 19.04 and
>   that way got newer QEMU 3.1.0 along vs QEMU 2.12.0 before. I have
>   noticed that everytime I start QEMU to run OSv, QEMU seems to hand
>   noticably longer (~1 second) before showing SeaBIOS output. I have
>   tried all kind of combinations to get rid of that pause and nothing
>   helped.
> 
>   Here is my start command:
>   time qemu-system-x86_64 -m 256M -smp 1 -nographic -nodefaults \
>    -device virtio-blk-pci,id=blk0,bootindex=0,drive=hd0,scsi=off \
>    -drive file=usr.img,if=none,id=hd0,cache=none,aio=thre\
>    -enable-kvm \
>    -cpu host,+x2apic -chardev stdio,mux=on,id=stdio,signal=off \
>    -mon chardev=stdio,mode=readline -device isa-serial,chardev=stdio
> 
>   It looks like qemu process starts, waits almost a second for something
>   and then print SeaBIOS splashscreen and continues boot:
> 
>   --> waits here
>   SeaBIOS (version 1.12.0-1)
>   Booting from Hard Disk..OSv v0.53.0-6-gc8395118
>   	disk read (real mode): 27.25ms, (+27.25ms)
>   	uncompress lzloader.elf: 46.22ms, (+18.97ms)
>   	TLS initialization: 46.79ms, (+0.57ms)
>   	.init functions: 47.82ms, (+1.03ms)
>   	SMP launched: 48.08ms, (+0.26ms)
>   	VFS initialized: 49.25ms, (+1.17ms)
>   	Network initialized: 49.48ms, (+0.24ms)
>   	pvpanic done: 49.57ms, (+0.08ms)
>   	pci enumerated: 52.42ms, (+2.85ms)
>   	drivers probe: 52.42ms, (+0.00ms)
>   	drivers loaded: 55.33ms, (+2.90ms)
>   	ROFS mounted: 56.37ms, (+1.04ms)
>   	Total time: 56.37ms, (+0.00ms)
>   Found optarg
>   dev  etc  hello  libenviron.so	libvdso.so  proc  tmp  tools  usr
> 
>   real	0m0.935s
>   user	0m0.426s
>   sys	0m0.490s
> 
>   With version 2.12.0 I used to see real below 200ms. So it seems qemu
>   slowed down 5 times.
> 
>   I ran strace -tt against it and I have noticed a pause here:
>   ...
>   07:31:41.848579 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.848604 futex(0x55c4a2ff6308, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
>   07:31:41.848649 ioctl(10, KVM_SET_PIT2, 0x7ffdd272d1f0) = 0
>   07:31:41.848674 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_KVMCLOCK_CTRL) = 1
>   07:31:41.848699 ioctl(10, KVM_SET_CLOCK, 0x7ffdd272d230) = 0
>   07:31:41.848724 futex(0x55c4a49a9a9c, FUTEX_WAKE_PRIVATE, 2147483647) = 1
>   07:31:41.848747 getpid()                = 5162
>   07:31:41.848769 tgkill(5162, 5166, SIGUSR1) = 0
>   07:31:41.848791 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.848814 futex(0x55c4a49a9a98, FUTEX_WAKE_PRIVATE, 2147483647) = 1
>   07:31:41.848837 getpid()                = 5162
>   07:31:41.848858 tgkill(5162, 5166, SIGUSR1) = 0
>   07:31:41.848889 write(8, "\1\0\0\0\0\0\0\0", 8) = 8
>   07:31:41.848919 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
>   07:31:41.848943 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=0}, NULL, 8) = 1 ([{fd=8, revents=POLLIN}], left {tv_sec=0, tv_nsec=0
>   })
>   07:31:41.849003 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
>   07:31:41.849031 read(8, "\5\0\0\0\0\0\0\0", 16) = 8
>   07:31:41.849064 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 0
>   07:31:41.849086 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=984624000}, NULL, 8) = 1 ([{fd=7, revents=POLLIN}], left {tv_sec=0, t
>   v_nsec=190532609})
> 
>   --> waits for almost 800ms
> 
>   07:31:42.643272 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
>   07:31:42.643522 read(7, "\1\0\0\0\0\0\0\0", 512) = 8
>   07:31:42.643625 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
>   07:31:42.643646 ppoll([{fd=0, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, 
>   {fd=8, events=POLLIN}], 5, {tv_sec=0, tv_nsec=190066000}, NULL, 8) = 2 ([{fd=4, revents=POLLIN}, {fd=8, revents=POL
>   LIN}], left {tv_sec=0, tv_nsec=189909632})
>   07:31:42.643836 futex(0x55c4a2fd34c0, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
>   07:31:42.643859 read(8, "\2\0\0\0\0\0\0\0", 16) = 8
>   07:31:42.643880 futex(0x55c4a2fd34c0, FUTEX_WAKE_PRIVATE, 1) = 1
> 
>   ...
> 
>   when I run same command using qemu 3.0.5 that I still happen to have
>   on the same machine that I built directly from source I see total boot
>   time at around 200ms. It seems like a regression.
> 
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/qemu/+bug/1826393/+subscriptions

Stefano Garzarella
Software Engineer @ Red Hat

Changed in qemu:
status:	New → Fix Released

Revision history for this message

Gerd Hoffmann (kraxel-redhat) wrote on 2019-05-14:

On Tue, May 14, 2019 at 10:04:14AM +0200, Stefano Garzarella wrote:
> On Mon, May 06, 2019 at 05:40:05PM -0000, Waldemar Kozaczuk wrote:
> > The last bios indeed helped. It knows runs under 200ms.
> >
> > Do you anticipate doing minor release of 3.1.0 with updated bios to address
> > this issue? Or users are expected to upgrade to QEMU 4.0.0?
>
> CCing Gerd
>
> I'm not sure we will release SeaBIOS 1.12.1 with a minor release of QEMU
> 3.1.0, so upgrading to QEMU 4.0 should be the way to address this issue.

I think with the 4.0 release 3.1 is EOL and there will be no more 3.1.x
stable releases ...

cheers,
Gerd

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.