qemu-devel.nongnu.org archive mirror
 help / color / mirror / Atom feed
From: "Dr. David Alan Gilbert" <dgilbert@redhat.com>
To: "Daniel P. Berrange" <berrange@redhat.com>, liang.z.li@intel.com
Cc: qemu-devel@nongnu.org
Subject: Re: [Qemu-devel] Hang with migration multi-thread compression under high load
Date: Wed, 27 Apr 2016 15:29:30 +0100	[thread overview]
Message-ID: <20160427142929.GC2290@work-vm> (raw)
In-Reply-To: <20160427142023.GC17937@redhat.com>

ccing in Liang Li

* Daniel P. Berrange (berrange@redhat.com) wrote:
> I've been testing various features of migration and have hit a problem
> with the multi-thread compression. It works fine when I have 2 or more
> threads, but if I tell it to only use a single thread, then it almost
> always hangs
> 
> I'm doing a migration between 2 guests on the same machine over a
> tcp localhost socket, using this command line to launch them:
> 
>   /home/berrange/src/virt/qemu/x86_64-softmmu/qemu-system-x86_64
>      -chardev socket,id=mon,path=/var/tmp/qemu-src-4644-monitor.sock
>      -mon chardev=mon,mode=control
>      -display none
>      -vga none
>      -machine accel=kvm
>      -kernel /boot/vmlinuz-4.4.7-300.fc23.x86_64
>      -initrd /home/berrange/src/virt/qemu/tests/migration/initrd-stress.img
>      -append "noapic edd=off printk.time=1 noreplace-smp cgroup_disable=memory pci=noearly console=ttyS0 debug ramsize=1"
>      -chardev stdio,id=cdev0
>      -device isa-serial,chardev=cdev0
>      -m 1536
>      -smp 1
> 
> The target VM also gets
> 
>     -incoming tcp:localhost:9000
> 
> 
> When the VM hangs, the source QEMU shows this stack trace:
> 
> 
> Thread 5 (Thread 0x7fdb0aa93700 (LWP 4648)):
> #0  0x00007fdb172d4c59 in syscall () at /lib64/libc.so.6
> #1  0x0000558bf0b9ba15 in qemu_event_wait (val=<optimized out>, ev=<optimized out>) at util/qemu-thread-posix.c:292
> #2  0x0000558bf0b9ba15 in qemu_event_wait (ev=ev@entry=0x558bf15acb44 <rcu_call_ready_event>) at util/qemu-thread-posix.c:399
> #3  0x0000558bf0ba9e3e in call_rcu_thread (opaque=<optimized out>) at util/rcu.c:250
> #4  0x00007fdb175a060a in start_thread () at /lib64/libpthread.so.0
> #5  0x00007fdb172daa4d in clone () at /lib64/libc.so.6
> 
> Thread 4 (Thread 0x7fdb0a292700 (LWP 4649)):
> #0  0x00007fdb172d0707 in ioctl () at /lib64/libc.so.6
> #1  0x0000558bf089b887 in kvm_vcpu_ioctl (cpu=cpu@entry=0x558bf268c8c0, type=type@entry=44672) at /home/berrange/src/virt/qemu/kvm-all.c:1984
> #2  0x0000558bf089b9df in kvm_cpu_exec (cpu=cpu@entry=0x558bf268c8c0) at /home/berrange/src/virt/qemu/kvm-all.c:1834
> #3  0x0000558bf0889982 in qemu_kvm_cpu_thread_fn (arg=0x558bf268c8c0) at /home/berrange/src/virt/qemu/cpus.c:1069
> #4  0x00007fdb175a060a in start_thread () at /lib64/libpthread.so.0
> #5  0x00007fdb172daa4d in clone () at /lib64/libc.so.6
> 
> Thread 3 (Thread 0x7fdaa3dff700 (LWP 4655)):
> #0  0x00007fdb175a5b10 in pthread_cond_wait@@GLIBC_2.3.2 () at /lib64/libpthread.so.0
> #1  0x0000558bf0b9b709 in qemu_cond_wait (cond=cond@entry=0x558bf42e28a8, mutex=mutex@entry=0x558bf42e2880) at util/qemu-thread-posix.c:123
> #2  0x0000558bf08ad40b in do_data_compress (opaque=0x558bf42e2870) at /home/berrange/src/virt/qemu/migration/ram.c:306
> #3  0x00007fdb175a060a in start_thread () at /lib64/libpthread.so.0
> #4  0x00007fdb172daa4d in clone () at /lib64/libc.so.6
> 
> Thread 2 (Thread 0x7fdaa35fe700 (LWP 4656)):
> #0  0x00007fdb175a909d in sendmsg () at /lib64/libpthread.so.0
> #1  0x0000558bf0b9ed35 in do_send_recv (sockfd=sockfd@entry=15, iov=iov@entry=0x7fda94031d40, iov_cnt=<optimized out>, do_send=do_send@entry=true) at util/iov.c:107
> #2  0x0000558bf0b9f2a4 in iov_send_recv (sockfd=15, _iov=_iov@entry=0x558bf267f130, iov_cnt=iov_cnt@entry=1, offset=offset@entry=0, bytes=bytes@entry=32768, do_send=do_send@entry=true) at util/iov.c:194
> #3  0x0000558bf0aaeacc in socket_writev_buffer (opaque=0x558bf2ebf1e0, iov=0x558bf267f130, iovcnt=1, pos=<optimized out>) at migration/qemu-file-unix.c:48
> #4  0x0000558bf0aad47a in qemu_fflush (f=f@entry=0x558bf2677100) at migration/qemu-file.c:123
> #5  0x0000558bf0aad5ed in qemu_put_buffer (f=0x558bf2677100, buf=buf@entry=0x558bf26ae840 "", size=size@entry=4045) at migration/qemu-file.c:337
> #6  0x0000558bf0aae040 in qemu_put_qemu_file (size=4045, buf=0x558bf26ae840 "", f=0x558bf2677100) at migration/qemu-file.c:642
> #7  0x0000558bf0aae040 in qemu_put_qemu_file (f_des=f_des@entry=0x558bf2677100, f_src=0x558bf26ae810) at migration/qemu-file.c:642
> #8  0x0000558bf08adf2d in ram_find_and_save_block (bytes_transferred=0x558bf116b050 <bytes_transferred>, offset=6647840, block=0x558bf26c5460, f=0x558bf2677100)
>     at /home/berrange/src/virt/qemu/migration/ram.c:886
> #9  0x0000558bf08adf2d in ram_find_and_save_block (bytes_transferred=0x558bf116b050 <bytes_transferred>, last_stage=<optimized out>, pss=<synthetic pointer>, f=0x558bf267---Type <return> to continue, or q <return> to quit---
> 7100) at /home/berrange/src/virt/qemu/migration/ram.c:972
> #10 0x0000558bf08adf2d in ram_find_and_save_block (bytes_transferred=0x558bf116b050 <bytes_transferred>, ms=<optimized out>, dirty_ram_abs=<optimized out>, last_stage=false, pss=<synthetic pointer>, f=0x558bf2677100) at /home/berrange/src/virt/qemu/migration/ram.c:1247
> #11 0x0000558bf08adf2d in ram_find_and_save_block (bytes_transferred=0x558bf116b050 <bytes_transferred>, dirty_ram_abs=<optimized out>, last_stage=<optimized out>, pss=<synthetic pointer>, f=<optimized out>, ms=<optimized out>) at /home/berrange/src/virt/qemu/migration/ram.c:1299
> #12 0x0000558bf08adf2d in ram_find_and_save_block (f=f@entry=0x558bf2677100, last_stage=last_stage@entry=false, bytes_transferred=0x558bf116b050 <bytes_transferred>)
>     at /home/berrange/src/virt/qemu/migration/ram.c:1359
> #13 0x0000558bf08ae211 in ram_save_iterate (f=0x558bf2677100, opaque=<optimized out>) at /home/berrange/src/virt/qemu/migration/ram.c:1993
> #14 0x0000558bf08b40e7 in qemu_savevm_state_iterate (f=0x558bf2677100, postcopy=postcopy@entry=false) at /home/berrange/src/virt/qemu/migration/savevm.c:970
> #15 0x0000558bf0aa9c74 in migration_thread (opaque=0x558bf10fa140 <current_migration>) at migration/migration.c:1694
> #16 0x00007fdb175a060a in start_thread () at /lib64/libpthread.so.0
> #17 0x00007fdb172daa4d in clone () at /lib64/libc.so.6
> 
> Thread 1 (Thread 0x7fdb23bedc80 (LWP 4647)):
> #0  0x00007fdb172cf0a1 in ppoll () at /lib64/libc.so.6
> #1  0x0000558bf0b06769 in qemu_poll_ns (__ss=0x0, __timeout=0x7ffe007c71c0, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/bits/poll2.h:77
> #2  0x0000558bf0b06769 in qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>, timeout=timeout@entry=1000000000) at qemu-timer.c:325
> #3  0x0000558bf0b061da in main_loop_wait (timeout=1000000000) at main-loop.c:252
> #4  0x0000558bf0b061da in main_loop_wait (nonblocking=<optimized out>) at main-loop.c:506
> #5  0x0000558bf0855a34 in main () at vl.c:1934
> #6  0x0000558bf0855a34 in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at vl.c:4658
> 
> 
> An strace of the source shows that the 'sendmsg' call in the source
> QEMU is not completing, which says that the socket buffer is full.
> So I think we can discount the source QEMU as being a problem.
> 
> 
> Now the target QEMU shows this stack trace:
> 
> 
> 
> Thread 4 (Thread 0x7f86de523700 (LWP 4652)):
> #0  0x00007f86ead64c59 in syscall () at /lib64/libc.so.6
> #1  0x0000560ecd8a2a15 in qemu_event_wait (val=<optimized out>, ev=<optimized out>) at util/qemu-thread-posix.c:292
> #2  0x0000560ecd8a2a15 in qemu_event_wait (ev=ev@entry=0x560ece2b3b44 <rcu_call_ready_event>) at util/qemu-thread-posix.c:399
> #3  0x0000560ecd8b0e3e in call_rcu_thread (opaque=<optimized out>) at util/rcu.c:250
> #4  0x00007f86eb03060a in start_thread () at /lib64/libpthread.so.0
> #5  0x00007f86ead6aa4d in clone () at /lib64/libc.so.6
> 
> Thread 3 (Thread 0x7f86ddd22700 (LWP 4653)):
> #0  0x00007f86eb035b10 in pthread_cond_wait@@GLIBC_2.3.2 () at /lib64/libpthread.so.0
> #1  0x0000560ecd8a2709 in qemu_cond_wait (cond=<optimized out>, mutex=mutex@entry=0x560ecde6f400 <qemu_global_mutex>)
>     at util/qemu-thread-posix.c:123
> #2  0x0000560ecd590943 in qemu_kvm_cpu_thread_fn (cpu=<optimized out>) at /home/berrange/src/virt/qemu/cpus.c:1035
> #3  0x0000560ecd590943 in qemu_kvm_cpu_thread_fn (arg=0x560ece73b8c0) at /home/berrange/src/virt/qemu/cpus.c:1074
> #4  0x00007f86eb03060a in start_thread () at /lib64/libpthread.so.0
> #5  0x00007f86ead6aa4d in clone () at /lib64/libc.so.6
> 
> Thread 2 (Thread 0x7f8677bed700 (LWP 4657)):
> #0  0x00007f86eb035b10 in pthread_cond_wait@@GLIBC_2.3.2 () at /lib64/libpthread.so.0
> #1  0x0000560ecd8a2709 in qemu_cond_wait (cond=cond@entry=0x560ed03918a0, mutex=mutex@entry=0x560ed0391878) at util/qemu-thread-posix.c:123
> #2  0x0000560ecd5b422d in do_data_decompress (opaque=0x560ed0391870) at /home/berrange/src/virt/qemu/migration/ram.c:2195
> #3  0x00007f86eb03060a in start_thread () at /lib64/libpthread.so.0
> #4  0x00007f86ead6aa4d in clone () at /lib64/libc.so.6
> 
> Thread 1 (Thread 0x7f86f767dc80 (LWP 4651)):
> #0  0x0000560ecd5b744f in ram_load (len=711, host=0x7f8677e06000, f=0x560ed03a7950) at /home/berrange/src/virt/qemu/migration/ram.c:2263
> #1  0x0000560ecd5b744f in ram_load (f=0x560ed03a7950, opaque=<optimized out>, version_id=<optimized out>)
>     at /home/berrange/src/virt/qemu/migration/ram.c:2513
> #2  0x0000560ecd5b8b87 in vmstate_load (f=0x560ed03a7950, se=0x560ece731f90, version_id=4)
>     at /home/berrange/src/virt/qemu/migration/savevm.c:643
> #3  0x0000560ecd5b8fc3 in qemu_loadvm_state_main (mis=0x560ece75c330, f=0x560ed03a7950) at /home/berrange/src/virt/qemu/migration/savevm.c:1819
> #4  0x0000560ecd5b8fc3 in qemu_loadvm_state_main (f=f@entry=0x560ed03a7950, mis=mis@entry=0x560ece75c330)
>     at /home/berrange/src/virt/qemu/migration/savevm.c:1850
> #5  0x0000560ecd5bbd36 in qemu_loadvm_state (f=f@entry=0x560ed03a7950) at /home/berrange/src/virt/qemu/migration/savevm.c:1911
> #6  0x0000560ecd7b1b2f in process_incoming_migration_co (opaque=0x560ed03a7950) at migration/migration.c:384
> #7  0x0000560ecd8b1eba in coroutine_trampoline (i0=<optimized out>, i1=<optimized out>) at util/coroutine-ucontext.c:78
> #8  0x00007f86eacb0f30 in __start_context () at /lib64/libc.so.6
> #9  0x00007ffc877e49c0 in  ()
> 
> 
> for some reason it isn't shown in the stack thrace for thread
> 1 above, when initially connecting GDB it says the main thread
> is at:
> 
> decompress_data_with_multi_threads (len=702, host=0x7fd78fe06000, f=0x55901af09950) at /home/berrange/src/virt/qemu/migration/ram.c:2254
> 2254	        for (idx = 0; idx < thread_count; idx++) {
> 
> 
> Looking at the target QEMU, we see  do_data_decompress method
> is waiting in a condition var:
> 
>         while (!param->start && !quit_decomp_thread) {
> 	    qemu_cond_wait(&param->cond, &param->mutex);
>             ....do stuff..
> 	    param->start = false
>         }
> 
> 
> Now the decompress_data_with_multi_threads is checking param->start without
> holding the param->mutex lock.
> 
> Changing decompress_data_with_multi_threads to acquire param->mutex
> lock makes it work, but isn't ideal, since that now blocks the
> decompress_data_with_multi_threads() method on the completion of
> each thread, which defeats the point of having multiple threads.
> 
> 
> As mentioned above I'm only seeing the hang when using 1 decompress
> thread. If it let QEMU have multiple decompress threads everything
> is fine. Also, it only happens if I have a very heavy guest workload.
> If the guest is completely idle, it again works fine. So clearly there
> is some kind of race condition I'm unlucky enough to hit here.
> 
> In terms of monitor commands I'm just running
> 
> 
>   migrate_set_capabilities compress on        (src + dst)
>   migrate_set_parameters compress-threads 1   (src only)
>   migrate_set_parameters decompress-threads 1 (dst only)
> 
> Then migrate -d tcp:localhost:9000
> 
> Regards,
> Daniel
> -- 
> |: http://berrange.com      -o-    http://www.flickr.com/photos/dberrange/ :|
> |: http://libvirt.org              -o-             http://virt-manager.org :|
> |: http://autobuild.org       -o-         http://search.cpan.org/~danberr/ :|
> |: http://entangle-photo.org       -o-       http://live.gnome.org/gtk-vnc :|
--
Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK

  reply	other threads:[~2016-04-27 14:29 UTC|newest]

Thread overview: 9+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2016-04-27 14:20 [Qemu-devel] Hang with migration multi-thread compression under high load Daniel P. Berrange
2016-04-27 14:29 ` Dr. David Alan Gilbert [this message]
2016-04-27 15:02   ` Daniel P. Berrange
2016-04-28  2:41     ` Li, Liang Z
2016-04-28  3:27 ` Li, Liang Z
2016-04-28  8:22   ` Daniel P. Berrange
2016-04-29  1:42     ` Li, Liang Z
2016-04-28 10:15 ` Daniel P. Berrange
2016-04-29  4:51   ` Li, Liang Z

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20160427142929.GC2290@work-vm \
    --to=dgilbert@redhat.com \
    --cc=berrange@redhat.com \
    --cc=liang.z.li@intel.com \
    --cc=qemu-devel@nongnu.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).