* [Qemu-devel] Hang with migration multi-thread compression under high load
@ 2016-04-27 14:20 Daniel P. Berrange
2016-04-27 14:29 ` Dr. David Alan Gilbert
` (2 more replies)
0 siblings, 3 replies; 9+ messages in thread
From: Daniel P. Berrange @ 2016-04-27 14:20 UTC (permalink / raw)
To: qemu-devel; +Cc: Dr. David Alan Gilbert
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(¶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 :|
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
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
2016-04-27 15:02 ` Daniel P. Berrange
2016-04-28 3:27 ` Li, Liang Z
2016-04-28 10:15 ` Daniel P. Berrange
2 siblings, 1 reply; 9+ messages in thread
From: Dr. David Alan Gilbert @ 2016-04-27 14:29 UTC (permalink / raw)
To: Daniel P. Berrange, liang.z.li; +Cc: qemu-devel
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(¶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
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
2016-04-27 14:29 ` Dr. David Alan Gilbert
@ 2016-04-27 15:02 ` Daniel P. Berrange
2016-04-28 2:41 ` Li, Liang Z
0 siblings, 1 reply; 9+ messages in thread
From: Daniel P. Berrange @ 2016-04-27 15:02 UTC (permalink / raw)
To: Dr. David Alan Gilbert; +Cc: liang.z.li, qemu-devel
On Wed, Apr 27, 2016 at 03:29:30PM +0100, Dr. David Alan Gilbert wrote:
> ccing in Liang Li
>
> * Daniel P. Berrange (berrange@redhat.com) wrote:
> > 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.
FWIW, the following patch also appears to "fix" the issue, presumably
by just making the race much less likely to hit:
diff --git a/migration/ram.c b/migration/ram.c
index 3f05738..be0233f 100644
--- a/migration/ram.c
+++ b/migration/ram.c
@@ -2271,6 +2271,7 @@ static void decompress_data_with_multi_threads(QEMUFile *f,
if (idx < thread_count) {
break;
}
+ sched_yield();
}
}
Incidentally IIUC, this decompress_data_with_multi_threads is just
busy waiting for a thread to become free, which seems pretty wasteful
of CPU resources. I wonder if there's a more effective way to structure
this, so that instead of having decompress_data_with_multi_threads()
choose which thread to pass the decompression job to, it just puts
the job into a queue, and then let all the threads pull from that
shared queue. IOW whichever thread the kerenl decides to wakeup would
get the job, without us having to explicitly assign a thread to the
job.
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 :|
^ permalink raw reply related [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
2016-04-27 15:02 ` Daniel P. Berrange
@ 2016-04-28 2:41 ` Li, Liang Z
0 siblings, 0 replies; 9+ messages in thread
From: Li, Liang Z @ 2016-04-28 2:41 UTC (permalink / raw)
To: Daniel P. Berrange, Dr. David Alan Gilbert; +Cc: qemu-devel@nongnu.org
> On Wed, Apr 27, 2016 at 03:29:30PM +0100, Dr. David Alan Gilbert wrote:
> > ccing in Liang Li
> >
> > * Daniel P. Berrange (berrange@redhat.com) wrote:
> > > 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.
>
> FWIW, the following patch also appears to "fix" the issue, presumably by just
> making the race much less likely to hit:
>
> diff --git a/migration/ram.c b/migration/ram.c index 3f05738..be0233f 100644
> --- a/migration/ram.c
> +++ b/migration/ram.c
> @@ -2271,6 +2271,7 @@ static void
> decompress_data_with_multi_threads(QEMUFile *f,
> if (idx < thread_count) {
> break;
> }
> + sched_yield();
> }
> }
>
>
> Incidentally IIUC, this decompress_data_with_multi_threads is just busy
> waiting for a thread to become free, which seems pretty wasteful of CPU
> resources. I wonder if there's a more effective way to structure this, so that
> instead of having decompress_data_with_multi_threads()
> choose which thread to pass the decompression job to, it just puts the job
> into a queue, and then let all the threads pull from that shared queue. IOW
> whichever thread the kerenl decides to wakeup would get the job, without
> us having to explicitly assign a thread to the job.
>
>
Thanks for reporting this issue, I will take a look and get back to you.
Liang
> 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 :|
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
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
@ 2016-04-28 3:27 ` Li, Liang Z
2016-04-28 8:22 ` Daniel P. Berrange
2016-04-28 10:15 ` Daniel P. Berrange
2 siblings, 1 reply; 9+ messages in thread
From: Li, Liang Z @ 2016-04-28 3:27 UTC (permalink / raw)
To: Daniel P. Berrange, qemu-devel@nongnu.org; +Cc: Dr. David Alan Gilbert
> 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:
>
What's the mean of "VM hangs", the VM has no response?
or just the live migration process can't not complete.
I do the test in my environment, it works for me.
Could you try to exec 'info migrate' in qemu monitor on the source side
to check if the live migration process is ongoing, if the 'transferred ram'
keeps unchanged, it shows dad lock happen.
Liang
> 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 :|
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
2016-04-28 3:27 ` Li, Liang Z
@ 2016-04-28 8:22 ` Daniel P. Berrange
2016-04-29 1:42 ` Li, Liang Z
0 siblings, 1 reply; 9+ messages in thread
From: Daniel P. Berrange @ 2016-04-28 8:22 UTC (permalink / raw)
To: Li, Liang Z; +Cc: qemu-devel@nongnu.org, Dr. David Alan Gilbert
On Thu, Apr 28, 2016 at 03:27:39AM +0000, Li, Liang Z 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:
> >
>
> What's the mean of "VM hangs", the VM has no response?
> or just the live migration process can't not complete.
The live migration process stops transferring any data, and the
monitor on the target host stops responding to input, because
the main thread is stuck in the the decompress_data_with_multi_threads
method.
> I do the test in my environment, it works for me.
NB, to make it more likely to happen you need to have a highly
loaded host - if the host is mostly idle it seems to work fine.
> Could you try to exec 'info migrate' in qemu monitor on the source side
> to check if the live migration process is ongoing, if the 'transferred ram'
> keeps unchanged, it shows dad lock happen.
The migration status is "active" and the transferred RAM is stuck
at approx 3-4 MB, not making any progress. As mentioned in the
description, the source QEMU is stuck in a blocking sendmsg() as
the TCP recv buffer is full on the target.
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 :|
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
2016-04-28 8:22 ` Daniel P. Berrange
@ 2016-04-29 1:42 ` Li, Liang Z
0 siblings, 0 replies; 9+ messages in thread
From: Li, Liang Z @ 2016-04-29 1:42 UTC (permalink / raw)
To: Daniel P. Berrange; +Cc: qemu-devel@nongnu.org, Dr. David Alan Gilbert
> On Thu, Apr 28, 2016 at 03:27:39AM +0000, Li, Liang Z 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:
> > >
> >
> > What's the mean of "VM hangs", the VM has no response?
> > or just the live migration process can't not complete.
>
> The live migration process stops transferring any data, and the monitor on
> the target host stops responding to input, because the main thread is stuck in
> the the decompress_data_with_multi_threads
> method.
>
> > I do the test in my environment, it works for me.
>
> NB, to make it more likely to happen you need to have a highly loaded host -
> if the host is mostly idle it seems to work fine.
>
> > Could you try to exec 'info migrate' in qemu monitor on the source
> > side to check if the live migration process is ongoing, if the 'transferred ram'
> > keeps unchanged, it shows dad lock happen.
>
> The migration status is "active" and the transferred RAM is stuck at approx 3-
> 4 MB, not making any progress. As mentioned in the description, the source
> QEMU is stuck in a blocking sendmsg() as the TCP recv buffer is full on the
> target.
>
I got it, thanks for your information!
Liang
>
> 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 :|
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
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
2016-04-28 3:27 ` Li, Liang Z
@ 2016-04-28 10:15 ` Daniel P. Berrange
2016-04-29 4:51 ` Li, Liang Z
2 siblings, 1 reply; 9+ messages in thread
From: Daniel P. Berrange @ 2016-04-28 10:15 UTC (permalink / raw)
To: qemu-devel; +Cc: Dr. David Alan Gilbert, Li, Liang Z
On Wed, Apr 27, 2016 at 03:20:23PM +0100, Daniel P. Berrange 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
[snip]
> Now the target QEMU shows this stack trace:
[snip]
> 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(¶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.
Ok, so I've investigated this further and decompress_data_with_multi_threads
is where I believe the flaw is. Its code is:
static void decompress_data_with_multi_threads(QEMUFile *f,
void *host, int len)
{
int idx, thread_count;
thread_count = migrate_decompress_threads();
while (true) {
for (idx = 0; idx < thread_count; idx++) {
if (!decomp_param[idx].start) {
qemu_get_buffer(f, decomp_param[idx].compbuf, len);
decomp_param[idx].des = host;
decomp_param[idx].len = len;
start_decompression(&decomp_param[idx]);
break;
}
}
if (idx < thread_count) {
break;
}
}
}
Looking at the dissembly for the start of that method we have:
for (idx = 0; idx < thread_count; idx++) {
358a: 45 85 f6 test %r14d,%r14d
358d: 7e fb jle 358a <ram_load+0x49a>
if (!decomp_param[idx].start) {
358f: 45 31 e4 xor %r12d,%r12d
3592: 40 84 ff test %dil,%dil
3595: 48 8d 42 78 lea 0x78(%rdx),%rax
3599: 0f 84 b1 04 00 00 je 3a50 <ram_load+0x960>
359f: 90 nop
Now asm is not my strong suit, but IIUC, that is showing that
the access to 'decomp_param[idx].start' is *not* accessing the
actual struct memory offset, but instead accessing a cached copy
in the %dil register. This is valid because we've not told the
compiler that this struct variable can be modified by multiple
threads at once.
So when the corresponding do_data_decompress() method sets
'decomp_param[idx].start = false', this is never seen by the
decompress_data_with_multi_threads() method.
If decompress_data_with_multi_threads() used a mutex lock
around its access to 'decomp_param[idx].start', then there
would be a memory barrier and the code would not be checking
the value cached in the %dil register.
Now we don't want a mutex lock in this code, but we do still
need to have a memory barrier here, so I think we need this
patch:
diff --git a/migration/ram.c b/migration/ram.c
index be0233f..fddc136 100644
--- a/migration/ram.c
+++ b/migration/ram.c
@@ -2260,6 +2260,7 @@ static void decompress_data_with_multi_threads(QEMUFile *f,
thread_count = migrate_decompress_threads();
while (true) {
for (idx = 0; idx < thread_count; idx++) {
+ smp_mb();
if (!decomp_param[idx].start) {
qemu_get_buffer(f, decomp_param[idx].compbuf, len);
decomp_param[idx].des = host;
Running my test case with that applied certainly makes migration
run as normal without the hangs I see currently
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 :|
^ permalink raw reply related [flat|nested] 9+ messages in thread
* Re: [Qemu-devel] Hang with migration multi-thread compression under high load
2016-04-28 10:15 ` Daniel P. Berrange
@ 2016-04-29 4:51 ` Li, Liang Z
0 siblings, 0 replies; 9+ messages in thread
From: Li, Liang Z @ 2016-04-29 4:51 UTC (permalink / raw)
To: Daniel P. Berrange, qemu-devel@nongnu.org; +Cc: Dr. David Alan Gilbert
[-- Attachment #1: Type: text/plain, Size: 6835 bytes --]
> On Wed, Apr 27, 2016 at 03:20:23PM +0100, Daniel P. Berrange 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
>
> [snip]
>
> > Now the target QEMU shows this stack trace:
>
> [snip]
>
> > 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(¶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.
>
> Ok, so I've investigated this further and
> decompress_data_with_multi_threads
> is where I believe the flaw is. Its code is:
>
> static void decompress_data_with_multi_threads(QEMUFile *f,
> void *host, int len) {
> int idx, thread_count;
>
> thread_count = migrate_decompress_threads();
> while (true) {
> for (idx = 0; idx < thread_count; idx++) {
> if (!decomp_param[idx].start) {
> qemu_get_buffer(f, decomp_param[idx].compbuf, len);
> decomp_param[idx].des = host;
> decomp_param[idx].len = len;
> start_decompression(&decomp_param[idx]);
> break;
> }
> }
> if (idx < thread_count) {
> break;
> }
> }
> }
>
>
> Looking at the dissembly for the start of that method we have:
>
> for (idx = 0; idx < thread_count; idx++) {
> 358a: 45 85 f6 test %r14d,%r14d
> 358d: 7e fb jle 358a <ram_load+0x49a>
> if (!decomp_param[idx].start) {
> 358f: 45 31 e4 xor %r12d,%r12d
> 3592: 40 84 ff test %dil,%dil
> 3595: 48 8d 42 78 lea 0x78(%rdx),%rax
> 3599: 0f 84 b1 04 00 00 je 3a50 <ram_load+0x960>
> 359f: 90 nop
>
>
> Now asm is not my strong suit, but IIUC, that is showing that the access to
> 'decomp_param[idx].start' is *not* accessing the actual struct memory
> offset, but instead accessing a cached copy in the %dil register. This is valid
> because we've not told the compiler that this struct variable can be modified
> by multiple threads at once.
>
> So when the corresponding do_data_decompress() method sets
> 'decomp_param[idx].start = false', this is never seen by the
> decompress_data_with_multi_threads() method.
>
> If decompress_data_with_multi_threads() used a mutex lock around its
> access to 'decomp_param[idx].start', then there would be a memory barrier
> and the code would not be checking the value cached in the %dil register.
>
> Now we don't want a mutex lock in this code, but we do still need to have a
> memory barrier here, so I think we need this
> patch:
>
> diff --git a/migration/ram.c b/migration/ram.c index be0233f..fddc136 100644
> --- a/migration/ram.c
> +++ b/migration/ram.c
> @@ -2260,6 +2260,7 @@ static void
> decompress_data_with_multi_threads(QEMUFile *f,
> thread_count = migrate_decompress_threads();
> while (true) {
> for (idx = 0; idx < thread_count; idx++) {
> + smp_mb();
> if (!decomp_param[idx].start) {
> qemu_get_buffer(f, decomp_param[idx].compbuf, len);
> decomp_param[idx].des = host;
>
>
> Running my test case with that applied certainly makes migration run as
> normal without the hangs I see currently
>
>
Yes, you patch can fix the issue, but the busy loop is not good. We have to fix this.
This is a patch which follows the pattern of the compression code. I think it can fix this issue too.
Could you help to test if it works in your environment?
Liang
> 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 :|
[-- Attachment #2: fix_multiple_thread_decompression_issue.patch --]
[-- Type: application/octet-stream, Size: 4020 bytes --]
diff --git a/migration/ram.c b/migration/ram.c
index 3f05738..7ab6ab5 100644
--- a/migration/ram.c
+++ b/migration/ram.c
@@ -263,6 +263,7 @@ typedef struct CompressParam CompressParam;
struct DecompressParam {
bool start;
+ bool done;
QemuMutex mutex;
QemuCond cond;
void *des;
@@ -287,6 +288,8 @@ static bool quit_comp_thread;
static bool quit_decomp_thread;
static DecompressParam *decomp_param;
static QemuThread *decompress_threads;
+static QemuMutex decomp_done_lock;
+static QemuCond decomp_done_cond;
static int do_compress_ram_page(CompressParam *param);
@@ -834,6 +837,7 @@ static inline void start_compression(CompressParam *param)
static inline void start_decompression(DecompressParam *param)
{
+ param->done = false;
qemu_mutex_lock(¶m->mutex);
param->start = true;
qemu_cond_signal(¶m->cond);
@@ -2193,19 +2197,24 @@ static void *do_data_decompress(void *opaque)
qemu_mutex_lock(¶m->mutex);
while (!param->start && !quit_decomp_thread) {
qemu_cond_wait(¶m->cond, ¶m->mutex);
+ }
+ if (!quit_decomp_thread) {
pagesize = TARGET_PAGE_SIZE;
- if (!quit_decomp_thread) {
- /* uncompress() will return failed in some case, especially
- * when the page is dirted when doing the compression, it's
- * not a problem because the dirty page will be retransferred
- * and uncompress() won't break the data in other pages.
- */
- uncompress((Bytef *)param->des, &pagesize,
- (const Bytef *)param->compbuf, param->len);
- }
- param->start = false;
+ /* uncompress() will return failed in some case, especially
+ * when the page is dirted when doing the compression, it's
+ * not a problem because the dirty page will be retransferred
+ * and uncompress() won't break the data in other pages.
+ */
+ uncompress((Bytef *)param->des, &pagesize,
+ (const Bytef *)param->compbuf, param->len);
}
+ param->start = false;
qemu_mutex_unlock(¶m->mutex);
+
+ qemu_mutex_lock(&decomp_done_lock);
+ param->done = true;
+ qemu_cond_signal(&decomp_done_cond);
+ qemu_mutex_unlock(&decomp_done_lock);
}
return NULL;
@@ -2219,10 +2228,13 @@ void migrate_decompress_threads_create(void)
decompress_threads = g_new0(QemuThread, thread_count);
decomp_param = g_new0(DecompressParam, thread_count);
quit_decomp_thread = false;
+ qemu_mutex_init(&decomp_done_lock);
+ qemu_cond_init(&decomp_done_cond);
for (i = 0; i < thread_count; i++) {
qemu_mutex_init(&decomp_param[i].mutex);
qemu_cond_init(&decomp_param[i].cond);
decomp_param[i].compbuf = g_malloc0(compressBound(TARGET_PAGE_SIZE));
+ decomp_param[i].done = true;
qemu_thread_create(decompress_threads + i, "decompress",
do_data_decompress, decomp_param + i,
QEMU_THREAD_JOINABLE);
@@ -2258,9 +2270,10 @@ static void decompress_data_with_multi_threads(QEMUFile *f,
int idx, thread_count;
thread_count = migrate_decompress_threads();
+ qemu_mutex_lock(&decomp_done_lock);
while (true) {
for (idx = 0; idx < thread_count; idx++) {
- if (!decomp_param[idx].start) {
+ if (decomp_param[idx].done) {
qemu_get_buffer(f, decomp_param[idx].compbuf, len);
decomp_param[idx].des = host;
decomp_param[idx].len = len;
@@ -2270,8 +2283,11 @@ static void decompress_data_with_multi_threads(QEMUFile *f,
}
if (idx < thread_count) {
break;
+ } else {
+ qemu_cond_wait(&decomp_done_cond, &decomp_done_lock);
}
}
+ qemu_mutex_unlock(&decomp_done_lock);
}
/*
^ permalink raw reply related [flat|nested] 9+ messages in thread
end of thread, other threads:[~2016-04-29 4:52 UTC | newest]
Thread overview: 9+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
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
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
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).