diff options
Diffstat (limited to 'results/classifier/108/other/1826393')
| -rw-r--r-- | results/classifier/108/other/1826393 | 727 |
1 files changed, 727 insertions, 0 deletions
diff --git a/results/classifier/108/other/1826393 b/results/classifier/108/other/1826393 new file mode 100644 index 00000000..99241590 --- /dev/null +++ b/results/classifier/108/other/1826393 @@ -0,0 +1,727 @@ +graphic: 0.822 +performance: 0.773 +other: 0.760 +semantic: 0.729 +permissions: 0.709 +device: 0.693 +debug: 0.666 +boot: 0.655 +network: 0.596 +PID: 0.573 +socket: 0.530 +files: 0.500 +vnc: 0.488 +KVM: 0.485 + +QEMU 3.1.0 stuck waiting for 800ms (5 times slower) in pre-bios phase + +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. + +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 +> + + +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 ... + + + + +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. + + +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 + + + +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: + +> 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 +> + + +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_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 + + +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 + + + |