Bug 812654 - libvirt slow respond
Summary: libvirt slow respond
Keywords:
Status: CLOSED DEFERRED
Alias: None
Product: Virtualization Tools
Classification: Community
Component: libvirt
Version: unspecified
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Libvirt Maintainers
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-04-15 18:46 UTC by stalker37
Modified: 2016-03-23 21:14 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-03-23 21:14:38 UTC
Embargoed:

Attachments (Terms of Use)
libvirtd debug log (72.65 KB, application/x-gzip)
2012-04-16 14:01 UTC, stalker37 		no flags Details
View All

Description stalker37 2012-04-15 18:46:28 UTC 
Description of problem:

Libvirt slow responding afterreboot or restart service

Version-Release number of selected component (if applicable):
0.9.11

How reproducible:

reboot server otr rstart libvirtd

Steps to Reproduce:
1. restart service
2. run virsh list or virt-install or some other
3. wait some time (other 20s)
  
Actual results:

LIBVIRT_DEFAULT_URI=qemu:///system time virsh -r list
 ID    Имя                         Статус
----------------------------------------------------
 1     debian6.0                      работает

0.00user 0.00system 0:28.29elapsed 0%CPU (0avgtext+0avgdata 21520maxresident)k
0inputs+0outputs (0major+1809minor)pagefaults 0swaps 

Expected results:

time < 5s

Additional info:

cpu core i7, kernel version is 3.3.1

strace ony time show
futex(0x7d1f84, FUTEX_WAIT_PRIVATE, 3, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x7d1f84, FUTEX_WAIT_PRIVATE, 5, NULL <detached ...>

in strace of any threads (strace -p $PID -ff -o /opt/virtdebug.log)

gdb show

gdb) thread apply all bt

Thread 12 (Thread 0x7fe79b919700 (LWP 9846)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe79b919700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()

Thread 11 (Thread 0x7fe79b118700 (LWP 9847)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe79b118700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()

Thread 10 (Thread 0x7fe79a917700 (LWP 9848)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe79a917700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()
---Type <return> to continue, or q <return> to quit---

Thread 9 (Thread 0x7fe79a116700 (LWP 9849)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe79a116700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()

Thread 8 (Thread 0x7fe799915700 (LWP 9850)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe799915700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()

Thread 7 (Thread 0x7fe799114700 (LWP 9851)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe799114700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()
---Type <return> to continue, or q <return> to quit---

Thread 6 (Thread 0x7fe798913700 (LWP 9852)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe798913700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()

Thread 5 (Thread 0x7fe798112700 (LWP 9853)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe798112700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()

Thread 4 (Thread 0x7fe797911700 (LWP 9854)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe797911700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()
---Type <return> to continue, or q <return> to quit---

Thread 3 (Thread 0x7fe797110700 (LWP 9855)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x000000000050ba1a in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
#2  0x000000000050af9b in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
#3  0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#4  0x00007fe79f65f9aa in start_thread (arg=0x7fe797110700) at pthread_create.c:297
#5  0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#6  0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7fe795157700 (LWP 9856)):
#0  0x00007fe79f1b5703 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>)
    at ../sysdeps/unix/sysv/linux/poll.c:87
#1  0x00000000004f4bc7 in virCommandProcessIO (cmd=0x7fe7900030e0, exitstatus=0x7fe795156b8c) at util/command.c:1742
#2  virCommandRun (cmd=0x7fe7900030e0, exitstatus=0x7fe795156b8c) at util/command.c:1984
#3  0x00000000004f5f54 in virRun (argv=<value optimized out>, status=0x7fe795156b8c) at util/command.c:698
#4  0x0000000000510919 in virFileWaitForDevices () at util/util.c:2611
#5  0x00000000004dc628 in virStorageBackendLogicalRefreshPool (conn=<value optimized out>, pool=0x7fe790007600) at storage/storage_backend_logical.c:588
#6  0x00000000004d45c9 in storageDriverAutostart (driver=<value optimized out>) at storage/storage_driver.c:109
#7  0x00000000004d49c6 in storageDriverStartup (privileged=<value optimized out>) at storage/storage_driver.c:178
#8  0x00007fe79f95c994 in virStateInitialize (privileged=1) at libvirt.c:852
#9  0x0000000000422205 in daemonRunStateInit (opaque=0x7d1e30) at libvirtd.c:1178
#10 0x000000000050b6b6 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
#11 0x00007fe79f65f9aa in start_thread (arg=0x7fe795157700) at pthread_create.c:297
#12 0x00007fe79f1be14d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#13 0x0000000000000000 in ?? ()

---Type <return> to continue, or q <return> to quit---
Thread 1 (Thread 0x7fe7a20bf840 (LWP 9845)):
#0  0x00007fe79f1b5703 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>)
    at ../sysdeps/unix/sysv/linux/poll.c:87
#1  0x00000000004fadd0 in virEventPollRunOnce () at util/event_poll.c:620
#2  0x00000000004f99e5 in virEventRunDefaultImpl () at util/event.c:247
#3  0x00007fe79f9b96dd in virNetServerRun (srv=0x7d1e30) at rpc/virnetserver.c:736
#4  0x0000000000423f2c in main (argc=<value optimized out>, argv=<value optimized out>) at libvirtd.c:1609
Comment 1 stalker37 2012-04-16 07:39:14 UTC 
UPD:
if i undefine pool with pre-defined LVM volume group (on it group exists some other lv) - libvirt respond shortly.

<pool type='logical'>
  <name>LVM_MAIN</name>
  <uuid>a2713bed-ad4a-fb79-83b5-65a9e8f1094e</uuid>
  <capacity>0</capacity>
  <allocation>0</allocation>
  <available>0</available>
  <source>
    <name>LVM_MAIN</name>
    <format type='unknown'/>
  </source>
  <target>
    <path>/dev/LVM_MAIN</path>
    <permissions>
      <mode>0700</mode>
      <owner>-1</owner>
      <group>-1</group>
    </permissions>
  </target>
</pool>
Comment 2 stalker37 2012-04-16 14:00:33 UTC 
i8n attach debug log of libvirtd
slow not lvm commands
Comment 3 stalker37 2012-04-16 14:01:29 UTC 
Created attachment 577722 [details]
libvirtd debug log
Comment 4 stalker37 2012-04-16 16:28:34 UTC 
downgrade kernel to 2.6.32 solve  problem
Comment 5 Cole Robinson 2016-03-23 21:14:38 UTC 
The hang on WaitForDevices and the kernel downgrade fix means this must have been some transient kernel breakage
Note You need to log in before you can comment on or make changes to this bug.