From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:36896) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1avQTB-0003DZ-O8 for qemu-devel@nongnu.org; Wed, 27 Apr 2016 10:29:39 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1avQT8-0004wf-DK for qemu-devel@nongnu.org; Wed, 27 Apr 2016 10:29:37 -0400 Received: from mx1.redhat.com ([209.132.183.28]:42410) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1avQT8-0004wa-5z for qemu-devel@nongnu.org; Wed, 27 Apr 2016 10:29:34 -0400 Date: Wed, 27 Apr 2016 15:29:30 +0100 From: "Dr. David Alan Gilbert" Message-ID: <20160427142929.GC2290@work-vm> References: <20160427142023.GC17937@redhat.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20160427142023.GC17937@redhat.com> Subject: Re: [Qemu-devel] Hang with migration multi-thread compression under high load List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: "Daniel P. Berrange" , liang.z.li@intel.com Cc: qemu-devel@nongnu.org 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=, ev=) at util/qemu-thread-posix.c:292 > #2 0x0000558bf0b9ba15 in qemu_event_wait (ev=ev@entry=0x558bf15acb44 ) at util/qemu-thread-posix.c:399 > #3 0x0000558bf0ba9e3e in call_rcu_thread (opaque=) 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=, 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=) 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 , 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 , last_stage=, pss=, f=0x558bf267---Type to continue, or q to quit--- > 7100) at /home/berrange/src/virt/qemu/migration/ram.c:972 > #10 0x0000558bf08adf2d in ram_find_and_save_block (bytes_transferred=0x558bf116b050 , ms=, dirty_ram_abs=, last_stage=false, pss=, f=0x558bf2677100) at /home/berrange/src/virt/qemu/migration/ram.c:1247 > #11 0x0000558bf08adf2d in ram_find_and_save_block (bytes_transferred=0x558bf116b050 , dirty_ram_abs=, last_stage=, pss=, f=, ms=) 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 ) > at /home/berrange/src/virt/qemu/migration/ram.c:1359 > #13 0x0000558bf08ae211 in ram_save_iterate (f=0x558bf2677100, opaque=) 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 ) 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=, __fds=) at /usr/include/bits/poll2.h:77 > #2 0x0000558bf0b06769 in qemu_poll_ns (fds=, nfds=, 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=) at main-loop.c:506 > #5 0x0000558bf0855a34 in main () at vl.c:1934 > #6 0x0000558bf0855a34 in main (argc=, argv=, envp=) 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=, ev=) at util/qemu-thread-posix.c:292 > #2 0x0000560ecd8a2a15 in qemu_event_wait (ev=ev@entry=0x560ece2b3b44 ) at util/qemu-thread-posix.c:399 > #3 0x0000560ecd8b0e3e in call_rcu_thread (opaque=) 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=, mutex=mutex@entry=0x560ecde6f400 ) > at util/qemu-thread-posix.c:123 > #2 0x0000560ecd590943 in qemu_kvm_cpu_thread_fn (cpu=) 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=, version_id=) > 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=, i1=) 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(¶m->cond, ¶m->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