qemu-img hangs on high core count ARM system

Bug #1805256 reported by dann frazier on 2018-11-26
20
This bug affects 2 people
Affects Status Importance Assigned to Milestone
QEMU
Undecided
Unassigned
qemu (Ubuntu)
Undecided
Unassigned

Bug Description

On the HiSilicon D06 system - a 96 core NUMA arm64 box - qemu-img frequently hangs (~50% of the time) with this command:

qemu-img convert -f qcow2 -O qcow2 /tmp/cloudimg /tmp/cloudimg2

Where "cloudimg" is a standard qcow2 Ubuntu cloud image. This qcow2->qcow2 conversion happens to be something uvtool does every time it fetches images.

Once hung, attaching gdb gives the following backtrace:

(gdb) bt
#0 0x0000ffffae4f8154 in __GI_ppoll (fds=0xaaaae8a67dc0, nfds=187650274213760,
    timeout=<optimized out>, timeout@entry=0x0, sigmask=0xffffc123b950)
    at ../sysdeps/unix/sysv/linux/ppoll.c:39
#1 0x0000aaaabbefaf00 in ppoll (__ss=0x0, __timeout=0x0, __nfds=<optimized out>,
    __fds=<optimized out>) at /usr/include/aarch64-linux-gnu/bits/poll2.h:77
#2 qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>,
    timeout=timeout@entry=-1) at util/qemu-timer.c:322
#3 0x0000aaaabbefbf80 in os_host_main_loop_wait (timeout=-1)
    at util/main-loop.c:233
#4 main_loop_wait (nonblocking=<optimized out>) at util/main-loop.c:497
#5 0x0000aaaabbe2aa30 in convert_do_copy (s=0xffffc123bb58) at qemu-img.c:1980
#6 img_convert (argc=<optimized out>, argv=<optimized out>) at qemu-img.c:2456
#7 0x0000aaaabbe2333c in main (argc=7, argv=<optimized out>) at qemu-img.c:4975

Reproduced w/ latest QEMU git (@ 53744e0a182)

John Snow (jnsnow) wrote :

Hi, can you do a `thread apply all bt` instead? If I were to bet, we're probably waiting for some slow call like lseek to return in another thread.

What filesystem/blockdevice is involved here?

dann frazier (dannf) wrote :

ext4 filesystem, SATA drive:

(gdb) thread apply all bt

Thread 3 (Thread 0xffff9bffc9a0 (LWP 9015)):
#0 0x0000ffffaaa462cc in __GI___sigtimedwait (set=<optimized out>,
    set@entry=0xaaaae725c070, info=info@entry=0xffff9bffbf18,
    timeout=0x3ff0000000000001, timeout@entry=0x0)
    at ../sysdeps/unix/sysv/linux/sigtimedwait.c:42
#1 0x0000ffffaab7dfac in __sigwait (set=set@entry=0xaaaae725c070,
    sig=sig@entry=0xffff9bffbff4) at ../sysdeps/unix/sysv/linux/sigwait.c:28
#2 0x0000aaaad998a628 in sigwait_compat (opaque=0xaaaae725c070)
    at util/compatfd.c:36
#3 0x0000aaaad998bce0 in qemu_thread_start (args=<optimized out>)
    at util/qemu-thread-posix.c:498
#4 0x0000ffffaab73088 in start_thread (arg=0xffffc528531f)
    at pthread_create.c:463
#5 0x0000ffffaaae34ec in thread_start ()
    at ../sysdeps/unix/sysv/linux/aarch64/clone.S:78

Thread 2 (Thread 0xffffa0e779a0 (LWP 9014)):
#0 syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1 0x0000aaaad998c9e8 in qemu_futex_wait (val=<optimized out>, f=<optimized out>)
    at /home/ubuntu/qemu/include/qemu/futex.h:29
#2 qemu_event_wait (ev=ev@entry=0xaaaad9a091c0 <rcu_call_ready_event>)
    at util/qemu-thread-posix.c:442
#3 0x0000aaaad99a6834 in call_rcu_thread (opaque=<optimized out>)
    at util/rcu.c:261
#4 0x0000aaaad998bce0 in qemu_thread_start (args=<optimized out>)
    at util/qemu-thread-posix.c:498
#5 0x0000ffffaab73088 in start_thread (arg=0xffffc528542f)
    at pthread_create.c:463
#6 0x0000ffffaaae34ec in thread_start ()
    at ../sysdeps/unix/sysv/linux/aarch64/clone.S:78

Thread 1 (Thread 0xffffa0fa8010 (LWP 9013)):
#0 0x0000ffffaaada154 in __GI_ppoll (fds=0xaaaae7291dc0, nfds=187650771816320,
    timeout=<optimized out>, timeout@entry=0x0, sigmask=0xffffc52852e0)
    at ../sysdeps/unix/sysv/linux/ppoll.c:39
#1 0x0000aaaad9987f00 in ppoll (__ss=0x0, __timeout=0x0, __nfds=<optimized out>,
    __fds=<optimized out>) at /usr/include/aarch64-linux-gnu/bits/poll2.h:77
#2 qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>,
    timeout=timeout@entry=-1) at util/qemu-timer.c:322
#3 0x0000aaaad9988f80 in os_host_main_loop_wait (timeout=-1)
    at util/main-loop.c:233
#4 main_loop_wait (nonblocking=<optimized out>) at util/main-loop.c:497
#5 0x0000aaaad98b7a30 in convert_do_copy (s=0xffffc52854e8) at qemu-img.c:1980
#6 img_convert (argc=<optimized out>, argv=<optimized out>) at qemu-img.c:2456
#7 0x0000aaaad98b033c in main (argc=7, argv=<optimized out>) at qemu-img.c:4975

Alex Bennée (ajbennee) on 2018-12-05
tags: added: qemu-img
贞贵李 (lizhengui) wrote :

Hi, I also found a problem that qemu-img convert hands in ARM.

The convert command line is "qemu-img convert -f qcow2 -O raw disk.qcow2 disk.raw ".

The bt is below:

Thread 2 (Thread 0x40000b776e50 (LWP 27215)):
#0 0x000040000a3f2994 in sigtimedwait () from /lib64/libc.so.6
#1 0x000040000a39c60c in sigwait () from /lib64/libpthread.so.0
#2 0x0000aaaaaae82610 in sigwait_compat (opaque=0xaaaac5163b00) at util/compatfd.c:37
#3 0x0000aaaaaae85038 in qemu_thread_start (args=args@entry=0xaaaac5163b90) at util/qemu_thread_posix.c:496
#4 0x000040000a3918bc in start_thread () from /lib64/libpthread.so.0
#5 0x000040000a492b2c in thread_start () from /lib64/libc.so.6

Thread 1 (Thread 0x40000b573370 (LWP 27214)):
#0 0x000040000a489020 in ppoll () from /lib64/libc.so.6
#1 0x0000aaaaaadaefc0 in ppoll (__ss=0x0, __timeout=0x0, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/bits/poll2.h:77
#2 qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>, timeout=<optimized out>) at qemu_timer.c:391
#3 0x0000aaaaaadae014 in os_host_main_loop_wait (timeout=<optimized out>) at main_loop.c:272
#4 0x0000aaaaaadae190 in main_loop_wait (nonblocking=<optimized out>) at main_loop.c:534
#5 0x0000aaaaaad97be0 in convert_do_copy (s=0xffffdc32eb48) at qemu-img.c:1923
#6 0x0000aaaaaada2d70 in img_convert (argc=<optimized out>, argv=<optimized out>) at qemu-img.c:2414
#7 0x0000aaaaaad99ac4 in main (argc=7, argv=<optimized out>) at qemu-img.c:5305

Do you find the cause of the problem and fix it? Thanks for your reply!

贞贵李 (lizhengui) wrote :

sorry, I make a spelling mistake here("Hi, I also found a problem that qemu-img convert hands in ARM.").The right is "I also found a problem that qemu-img convert hangs in ARM".

dann frazier (dannf) on 2019-04-15
Changed in qemu:
status: New → Confirmed
dann frazier (dannf) wrote :

No, sorry - this bugs still persists w/ latest upstream (@ afccfc0). I found a report of similar symptoms:

  https://patchwork.kernel.org/patch/10047341/
  https://bugzilla.redhat.com/show_bug.cgi?id=1524770#c13

To be clear, ^ is already fixed upstream, so it is not the *same* issue - but perhaps related.

贞贵李 (lizhengui) wrote :

Do you have any good ideas about it? Maybe somewhere lack of memeory barriers that cause it?

贞贵李 (lizhengui) wrote :

frazier, Do you find the conditions that necessarily make this problem appear?

贞贵李 (lizhengui) wrote :

I can reproduce this problem with qemu.git/matser. It still exists in qemu.git/matser. I found that when an IO return in worker threads and want to call aio_notify to wake up main_loop, but it found that ctx->notify_me is cleared to 0 by main_loop in aio_ctx_check by calling atomic_and(&ctx->notify_me, ~1) . So worker thread won't write enventfd to notify main_loop.If such a scene happens, the main_loop will hang:
    main loop worker thread1 worker thread2
-----------------------------------------------------------------------------------------------
    qemu_poll_ns aio_worker
                            qemu_bh_schedule(pool->completion_bh)
    glib_pollfds_poll
    g_main_context_check
    aio_ctx_check
    atomic_and(&ctx->notify_me, ~1) aio_worker
                                                      qemu_bh_schedule(pool->completion_bh)
    /* do something for event */
    qemu_poll_ns
    /* hangs !!!*/

As we known, ctx->notify_me will be visited by worker thread and main loop. I thank we should add a lock protection for ctx->notify_me to avoid this happend.what do you thank so?

dann frazier (dannf) on 2019-06-05
Changed in qemu (Ubuntu):
status: New → Confirmed
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

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