All of lore.kernel.org
 help / color / mirror / Atom feed
* [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload
@ 2016-05-13  6:41 chenwqin
  2016-05-13 15:01 ` Serge Hallyn
                   ` (9 more replies)
  0 siblings, 10 replies; 11+ messages in thread
From: chenwqin @ 2016-05-13  6:41 UTC (permalink / raw)
  To: qemu-devel

Public bug reported:

I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

Some information:
    Vendor      : HP
    Product     : HP ProLiant BL460c Gen9
    Kernel      : 3.16.0-4-amd64
    Disto       : Debian
    Version     : 8.4
    Arch        : amd64
    Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
    Ceph        : Hammer 0.94.5
    Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
    Qemu config : cache=none
    Qemu cpu&mem: 4core, 8GB

How can i reproduce the problem?

while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
(Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

My randwrite.sh script
----------------------------------------------
#!/bin/sh
sync
echo 3 > /proc/sys/vm/drop_caches

FILENAME=/dev/vdc
RUNTIME=100
BLOCKSIZE=4K
IOENGINE=libaio
RESULTFILE=fio-randwrite.log
IODEPTH=32
RAMP_TIME=5
SIZE=100G

fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
----------------------------------------------

What happened after the problem appear?
my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

Qemu Fio benchmark
----------------------------------------------------
Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
%Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
%Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
%Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
%Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
%Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
%Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
%Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
%Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
%Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

Anything I do?
I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
Here are the perf top output on host.
---------------------------------------------------------------
   PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
-------------------------------------------------------------------------------

    75.25%  [kernel]            [k] _raw_spin_lock
     1.17%  [kernel]            [k] futex_wait_setup
     0.86%  libc-2.19.so        [.] malloc
     0.58%  [kernel]            [k] futex_wake
     0.55%  libc-2.19.so        [.] 0x00000000000ea96f
     0.41%  [kernel]            [k] native_write_msr_safe
---------------------------------------------------------------

** 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/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/qemu/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
@ 2016-05-13 15:01 ` Serge Hallyn
  2016-05-13 15:10 ` [Qemu-devel] [Bug 1581334] " Josh Durgin
                   ` (8 subsequent siblings)
  9 siblings, 0 replies; 11+ messages in thread
From: Serge Hallyn @ 2016-05-13 15:01 UTC (permalink / raw)
  To: qemu-devel

affects linux


** Also affects: linux
   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/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/linux/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Qemu-devel] [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
  2016-05-13 15:01 ` Serge Hallyn
@ 2016-05-13 15:10 ` Josh Durgin
  2016-05-13 15:16 ` [Qemu-devel] [Bug 1581334] [NEW] " Serge Hallyn
                   ` (7 subsequent siblings)
  9 siblings, 0 replies; 11+ messages in thread
From: Josh Durgin @ 2016-05-13 15:10 UTC (permalink / raw)
  To: qemu-devel

Since this works fine with krbd, it sounds like the bug may be in
librbd. Could you install debug symbols (the librbd1-dbg package) and
when this occurs, attach to the qemu process with gdb and get a
backtrace of all threads (there will be a lot of them) via 'gdb -p $pid'
and in gdb 'thread apply all bt'?

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/linux/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
  2016-05-13 15:01 ` Serge Hallyn
  2016-05-13 15:10 ` [Qemu-devel] [Bug 1581334] " Josh Durgin
@ 2016-05-13 15:16 ` Serge Hallyn
  2016-05-13 16:37 ` [Qemu-devel] [Bug 1581334] " chenwqin
                   ` (6 subsequent siblings)
  9 siblings, 0 replies; 11+ messages in thread
From: Serge Hallyn @ 2016-05-13 15:16 UTC (permalink / raw)
  To: qemu-devel

affects ceph


** Also affects: ceph
   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/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Qemu-devel] [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
                   ` (2 preceding siblings ...)
  2016-05-13 15:16 ` [Qemu-devel] [Bug 1581334] [NEW] " Serge Hallyn
@ 2016-05-13 16:37 ` chenwqin
  2016-05-13 17:00 ` Jason Dillaman
                   ` (5 subsequent siblings)
  9 siblings, 0 replies; 11+ messages in thread
From: chenwqin @ 2016-05-13 16:37 UTC (permalink / raw)
  To: qemu-devel

Here are gdb oupout with librbd1-dbg and librados2-dbg.

---------------------------------------------------------
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
0x00007ff8cf8dddff in ppoll () from /lib/x86_64-linux-gnu/libc.so.6

Thread 522 (Thread 0x7ff8ccb56700 (LWP 4959)):
#0  0x00007ff8cf8e2809 in syscall () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ff8cf198012 in ?? () from /usr/lib/x86_64-linux-gnu/liblttng-ust.so.0
#2  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#3  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 521 (Thread 0x7ff8cc355700 (LWP 4960)):
#0  0x00007ff8cf8e2809 in syscall () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ff8cf198012 in ?? () from /usr/lib/x86_64-linux-gnu/liblttng-ust.so.0
#2  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#3  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 520 (Thread 0x7ff8cbb54700 (LWP 4961)):
#0  0x00007ff8cf8e2809 in syscall () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x0000000000833d00 in futex_wait (ev=0x1222e04 <rcu_call_ready_event>, val=4294967295) at util/qemu-thread-posix.c:292
#2  0x0000000000833e8e in qemu_event_wait (ev=0x1222e04 <rcu_call_ready_event>) at util/qemu-thread-posix.c:399
#3  0x0000000000849382 in call_rcu_thread (opaque=0x0) at util/rcu.c:250
#4  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 519 (Thread 0x7ff8cab1c700 (LWP 4974)):
#0  0x00007ff8cfbb508f in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007ff8d17a563b in ceph::log::Log::entry (this=0x1643a60) at log/Log.cc:353
#2  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#3  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 518 (Thread 0x7ff8c9b8d700 (LWP 4975)):
#0  0x00007ff8cfbb5438 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007ff8d1535acb in WaitUntil (when=..., mutex=..., this=0x1692bd8) at ./common/Cond.h:71
#2  WaitInterval (interval=..., mutex=..., cct=<optimized out>, this=0x1692bd8) at ./common/Cond.h:79
#3  CephContextServiceThread::entry (this=0x1692b60) at common/ceph_context.cc:96
#4  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6


Thread 517 (Thread 0x7ff8c938c700 (LWP 4976)):
#0  0x00007ff8cfbb5438 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007ff8d15125c1 in WaitUntil (when=..., mutex=..., this=0x1694978) at common/Cond.h:71
#2  SafeTimer::timer_thread (this=0x1694968) at common/Timer.cc:118
#3  0x00007ff8d1512efd in SafeTimerThread::entry (this=<optimized out>) at common/Timer.cc:38
#4  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 516 (Thread 0x7ff8c8b8b700 (LWP 4977)):
#0  0x00007ff8cfbb508f in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007ff8d1696b70 in Wait (mutex=..., this=0x1693f50) at ./common/Cond.h:55
#2  DispatchQueue::entry (this=0x1693ee8) at msg/simple/DispatchQueue.cc:196
#3  0x00007ff8d16c65fd in DispatchQueue::DispatchThread::entry (this=<optimized out>) at msg/simple/DispatchQueue.h:103
#4  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 515 (Thread 0x7ff8c838a700 (LWP 4978)):
#0  0x00007ff8cfbb508f in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007ff8d1699ba6 in Wait (mutex=..., this=0x16940f0) at ./common/Cond.h:55
#2  DispatchQueue::run_local_delivery (this=0x1693ee8) at msg/simple/DispatchQueue.cc:114
#3  0x00007ff8d16c66dd in DispatchQueue::LocalDeliveryThread::entry (this=<optimized out>) at msg/simple/DispatchQueue.h:117
#4  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 514 (Thread 0x7ff8c7b89700 (LWP 4979)):
#0  0x00007ff8cfbb508f in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007ff8d16bde99 in Wait (mutex=..., this=0x1694358) at ./common/Cond.h:55
#2  SimpleMessenger::reaper_entry (this=0x1693d20) at msg/simple/SimpleMessenger.cc:211
#3  0x00007ff8d16c6cdd in SimpleMessenger::ReaperThread::entry (this=<optimized out>) at msg/simple/SimpleMessenger.h:195
#4  0x00007ff8cfbb10a4 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007ff8cf8e687d in clone () from /lib/x86_64-linux-gnu/libc.so.6
........
........
........
(all the log in attachment: debug.log)
---------------------------------------------------------------------------

** Attachment added: "gdb thread apply all bt with librbd1-dbg and librados2-dbg"
   https://bugs.launchpad.net/qemu/+bug/1581334/+attachment/4662277/+files/debug.log

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Qemu-devel] [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
                   ` (3 preceding siblings ...)
  2016-05-13 16:37 ` [Qemu-devel] [Bug 1581334] " chenwqin
@ 2016-05-13 17:00 ` Jason Dillaman
  2016-05-14  1:28 ` chenwqin
                   ` (4 subsequent siblings)
  9 siblings, 0 replies; 11+ messages in thread
From: Jason Dillaman @ 2016-05-13 17:00 UTC (permalink / raw)
  To: qemu-devel

Can you run 'perf top' against just the QEMU process?  There was an
email chain from nearly a year ago about tcmalloc causing extremely high
'_raw_spin_lock' calls under high IOPS scenarios.

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Qemu-devel] [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
                   ` (4 preceding siblings ...)
  2016-05-13 17:00 ` Jason Dillaman
@ 2016-05-14  1:28 ` chenwqin
  2016-05-14  6:53 ` chenwqin
                   ` (3 subsequent siblings)
  9 siblings, 0 replies; 11+ messages in thread
From: chenwqin @ 2016-05-14  1:28 UTC (permalink / raw)
  To: qemu-devel

Here are 'perf top -p `pgrep qemu` -a` output; I met tcmalloc problem on the osd host and fix it with a larger TCMALLOC_MAX_TOTAL_THREAD_CACHE_BYTES. The perf top of tcmalloc problem is a little bit different of my problem.    
------------------------------------------------------------------
Samples: 15M of event 'cycles', Event count (approx.): 463535858808
  87.68%  [kernel]                 [k] _raw_spin_lock
   1.02%  [kernel]                 [k] futex_wait_setup
   0.66%  [kernel]                 [k] futex_wake
   0.47%  libc-2.19.so             [.] malloc
   0.42%  [kernel]                 [k] try_to_wake_up
   0.22%  [kernel]                 [k] __unqueue_futex
   0.22%  [kernel]                 [k] _raw_spin_lock_irq
   0.18%  libpthread-2.19.so       [.] pthread_mutex_lock
   0.18%  libc-2.19.so             [.] 0x00000000000f4dff
   0.17%  libc-2.19.so             [.] 0x00000000000ea96f
   0.15%  [kernel]                 [k] idle_cpu
   0.15%  libpthread-2.19.so       [.] __pthread_mutex_unlock_usercnt
   0.14%  [kernel]                 [k] get_futex_value_locked
   0.13%  [kernel]                 [k] get_futex_key_refs.isra.13
   0.13%  libc-2.19.so             [.] free
   0.12%  [kernel]                 [k] _raw_spin_lock_irqsave
   0.11%  [kernel]                 [k] update_curr
   0.11%  [kernel]                 [k] select_task_rq_fair
   0.10%  [kernel]                 [k] native_write_msr_safe
   0.10%  [kernel]                 [k] futex_wait_queue_me
   0.10%  [kernel]                 [k] __schedule
   0.09%  [kernel]                 [k] wake_futex
Press '?' for help on key bindings
----------------------------------------------------------------

Tcmalloc problem perf top (log from ceph bug tracer email, same with tcmalloc problem i met)
-------------------------------------------------------------
34.37%  libtcmalloc.so.4.1.2  [.] tcmalloc::CentralFreeList::FetchFromSpans
  18.06%  libtcmalloc.so.4.1.2  [.] tcmalloc::ThreadCache::ReleaseToCentralCache
  13.76%  libtcmalloc.so.4.1.2  [.] tcmalloc::CentralFreeList::ReleaseToSpans
   1.45%  libtcmalloc.so.4.1.2  [.] tcmalloc::CentralFreeList::RemoveRange
-------------------------------------------------------------

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Qemu-devel] [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
                   ` (5 preceding siblings ...)
  2016-05-14  1:28 ` chenwqin
@ 2016-05-14  6:53 ` chenwqin
  2016-05-14 12:12 ` Jason Dillaman
                   ` (2 subsequent siblings)
  9 siblings, 0 replies; 11+ messages in thread
From: chenwqin @ 2016-05-14  6:53 UTC (permalink / raw)
  To: qemu-devel

Some more test I have do:
1. running qemu with TCMALLOC_MAX_TOTAL_THREAD_CACHE_BYTES 256MB, still got problem
2. prevent cpu go into C3 and C6 state, still got problem
3. running qemu with aio=native, still got problem

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Qemu-devel] [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
                   ` (6 preceding siblings ...)
  2016-05-14  6:53 ` chenwqin
@ 2016-05-14 12:12 ` Jason Dillaman
  2021-04-22  5:10 ` Thomas Huth
  2021-06-18 15:19 ` Thomas Huth
  9 siblings, 0 replies; 11+ messages in thread
From: Jason Dillaman @ 2016-05-14 12:12 UTC (permalink / raw)
  To: qemu-devel

Any chance you can re-test with a more recent kernel on the hypervisor
host? If the spin-lock was coming from user-space, I would expect
futex_wait_setup and futex_wake to be much higher.

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  New

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
                   ` (7 preceding siblings ...)
  2016-05-14 12:12 ` Jason Dillaman
@ 2021-04-22  5:10 ` Thomas Huth
  2021-06-18 15:19 ` Thomas Huth
  9 siblings, 0 replies; 11+ messages in thread
From: Thomas Huth @ 2021-04-22  5:10 UTC (permalink / raw)
  To: qemu-devel

Looking through old bug tickets... can you still reproduce this issue
with the latest available versions? Or could we close this ticket
nowadays?

** Changed in: qemu
       Status: New => Incomplete

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  Incomplete

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions


^ permalink raw reply	[flat|nested] 11+ messages in thread

* [Bug 1581334] Re: qemu + librbd takes high %sy cpu under high random io workload
  2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
                   ` (8 preceding siblings ...)
  2021-04-22  5:10 ` Thomas Huth
@ 2021-06-18 15:19 ` Thomas Huth
  9 siblings, 0 replies; 11+ messages in thread
From: Thomas Huth @ 2021-06-18 15:19 UTC (permalink / raw)
  To: qemu-devel

Since there wasn't a reply within the last two months, I'm assuming this
doesn't affect QEMU anymore, thus I'm closing this ticket for QEMU now.

** Changed in: qemu
       Status: Incomplete => Won't Fix

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1581334

Title:
  qemu + librbd takes high %sy cpu under high random io workload

Status in Ceph:
  New
Status in Linux:
  New
Status in QEMU:
  Won't Fix

Bug description:
  I got an IO problem. When running Qemu + ceph(use librbd), and do a random IO benchmark or some high load random IO test, it will exhaust all my host cpu on %sy cpu.
  It doesn’t happen all the time, but when it appear it will reproduce every time I start a random IO benchmark(test with Fio).
  And the only way to fix the problem is shutdown my vm and start it, but the problem will happen again with high random IO load.

  Some information:
      Vendor      : HP
      Product     : HP ProLiant BL460c Gen9
      Kernel      : 3.16.0-4-amd64
      Disto       : Debian
      Version     : 8.4
      Arch        : amd64
      Qemu        : 2.1 ~ 2.6 (Yes, I already test the latest qemu2.6 version, but still got the problem)
      Ceph        : Hammer 0.94.5
      Librbd      : 0.94.5 ~ 10.2 (I rebuild librbd with ceph 10.2 source code, but the problem still here)
      Qemu config : cache=none
      Qemu cpu&mem: 4core, 8GB

  How can i reproduce the problem?

  while :; do bash randwrite.sh ; sleep 3600; done >test.log 2>&1 &
  (Sleep 3600 is the key to reproduce my problem. I don’t known how long sleep suit for reproduce, but one hour sleep is enough. the problem will easy reproduce after a long sleep, if i keep benchmark running without sleep, i can't reproduce it)

  My randwrite.sh script
  ----------------------------------------------
  #!/bin/sh
  sync
  echo 3 > /proc/sys/vm/drop_caches

  FILENAME=/dev/vdc
  RUNTIME=100
  BLOCKSIZE=4K
  IOENGINE=libaio
  RESULTFILE=fio-randwrite.log
  IODEPTH=32
  RAMP_TIME=5
  SIZE=100G

  fio --numjobs 10 --norandommap --randrepeat=0 --readwrite=randwrite --ramp_time=$RAMP_TIME --bs=$BLOCKSIZE --runtime=$RUNTIME --iodepth=$IODEPTH --filename=$FILENAME --ioengine=$IOENGINE --direct=1 --name=iops_randwrite --group_reporting  | tee $RESULTFILE
  ----------------------------------------------

  What happened after the problem appear?
  my vm will got huge IOPS drop. In my case, it will drop from 15000 IOPS to 3500 IOPS. And other thing, my host cpu will exhaust on %sy. Top output like this.

  Qemu Fio benchmark
  ----------------------------------------------------
  Tasks: 284 total,   2 running, 282 sleeping,   0 stopped,   0 zombie
  %Cpu0  : 11.8 us, 66.7 sy,  0.0 ni, 21.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu1  : 12.7 us, 64.9 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu2  : 13.7 us, 64.5 sy,  0.0 ni, 21.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu3  : 13.2 us, 64.1 sy,  0.0 ni, 22.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu4  : 11.7 us, 65.4 sy,  0.0 ni, 22.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu5  : 13.2 us, 64.4 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu6  : 12.4 us, 65.1 sy,  0.0 ni, 22.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu7  : 13.6 us, 63.8 sy,  0.0 ni, 22.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu8  :  9.8 us, 73.0 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu9  :  7.8 us, 74.5 sy,  0.0 ni, 17.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu10 :  6.0 us, 81.4 sy,  0.0 ni,  6.6 id,  0.0 wa,  0.0 hi,  6.0 si,  0.0 st
  %Cpu11 :  8.4 us, 79.5 sy,  0.0 ni,  8.8 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu12 :  7.6 us, 80.7 sy,  0.0 ni,  7.0 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
  %Cpu13 :  7.4 us, 79.9 sy,  0.0 ni,  7.7 id,  0.0 wa,  0.0 hi,  5.0 si,  0.0 st
  %Cpu14 :  9.8 us, 75.4 sy,  0.0 ni, 11.4 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu15 :  6.7 us, 80.1 sy,  0.0 ni, 10.1 id,  0.0 wa,  0.0 hi,  3.0 si,  0.0 st
  %Cpu16 :  9.2 us, 69.2 sy,  0.0 ni, 17.5 id,  0.0 wa,  0.0 hi,  4.1 si,  0.0 st
  %Cpu17 :  9.9 us, 66.6 sy,  0.0 ni, 20.1 id,  0.0 wa,  0.0 hi,  3.4 si,  0.0 st
  %Cpu18 : 16.6 us, 49.0 sy,  0.0 ni, 34.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu19 : 16.7 us, 46.4 sy,  0.0 ni, 36.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu20 : 13.0 us, 50.8 sy,  0.0 ni, 36.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu21 : 18.9 us, 46.2 sy,  0.0 ni, 34.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu22 : 12.1 us, 52.9 sy,  0.0 ni, 35.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu23 : 15.9 us, 47.6 sy,  0.0 ni, 36.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu24 :  6.7 us, 62.0 sy,  0.0 ni, 31.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu25 :  7.6 us, 63.7 sy,  0.0 ni, 28.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu26 :  8.1 us, 75.8 sy,  0.0 ni, 16.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu27 :  6.7 us, 73.6 sy,  0.0 ni, 19.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu28 :  9.2 us, 74.3 sy,  0.0 ni, 16.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu29 :  8.2 us, 73.3 sy,  0.0 ni, 18.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu30 :  4.4 us, 73.1 sy,  0.0 ni, 22.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  %Cpu31 :  7.5 us, 69.6 sy,  0.0 ni, 22.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:  13217662+total,  3721572 used, 12845504+free,   283228 buffers
  KiB Swap:  4194300 total,        0 used,  4194300 free.  2242976 cached Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  30349 root      20   0 25.381g 499892  20640 R  2495  0.4 119:11.98 qemu-system-x86

  Anything I do?
  I use perf top, profile to debug the problem. It show me that something like thread deadlock problem. Any I test QEMU with kernel RBD, it work fine.
  Here are the perf top output on host.
  ---------------------------------------------------------------
     PerfTop:   12393 irqs/sec  kernel:87.3%  exact:  0.0% [4000Hz cycles],  (all, 32 CPUs)
  -------------------------------------------------------------------------------

      75.25%  [kernel]            [k] _raw_spin_lock
       1.17%  [kernel]            [k] futex_wait_setup
       0.86%  libc-2.19.so        [.] malloc
       0.58%  [kernel]            [k] futex_wake
       0.55%  libc-2.19.so        [.] 0x00000000000ea96f
       0.41%  [kernel]            [k] native_write_msr_safe
  ---------------------------------------------------------------

To manage notifications about this bug go to:
https://bugs.launchpad.net/ceph/+bug/1581334/+subscriptions


^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2021-06-18 15:32 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-05-13  6:41 [Qemu-devel] [Bug 1581334] [NEW] qemu + librbd takes high %sy cpu under high random io workload chenwqin
2016-05-13 15:01 ` Serge Hallyn
2016-05-13 15:10 ` [Qemu-devel] [Bug 1581334] " Josh Durgin
2016-05-13 15:16 ` [Qemu-devel] [Bug 1581334] [NEW] " Serge Hallyn
2016-05-13 16:37 ` [Qemu-devel] [Bug 1581334] " chenwqin
2016-05-13 17:00 ` Jason Dillaman
2016-05-14  1:28 ` chenwqin
2016-05-14  6:53 ` chenwqin
2016-05-14 12:12 ` Jason Dillaman
2021-04-22  5:10 ` Thomas Huth
2021-06-18 15:19 ` Thomas Huth

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.