[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]

[libvirt] libvirt slow responding after restart of service



after service libvirtd restarted has go slow responding (virsh,virt-install and some other tools) lsof /var/run/libvirt/libvirt-sock-ro and attach strace to this $PID always show

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

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

gdb show only
(gdb) bt
#0 0x00007f938c1e3703 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 0x00007f938c9e76dd 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


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

and with LIBVIRT_DEBUG=1
LIBVIRT_DEBUG=1 LIBVIRT_DEFAULT_URI=qemu:///system time virsh -r list
2012-04-14 21:21:45.185+0000: 21338: info : libvirt version: 0.9.11, package: alt3M60P1 2012-04-14 21:21:45.185+0000: 21338: debug : virInitialize:414 : register drivers 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb22e8e0 name=Test 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering Test as driver 0 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterNetworkDriver:592 : registering Test as network driver 0 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterInterfaceDriver:625 : registering Test as interface driver 0 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterStorageDriver:658 : registering Test as storage driver 0 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDeviceMonitor:691 : registering Test as device driver 0 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterSecretDriver:724 : registering Test as secret driver 0 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterNWFilterDriver:757 : registering Test as network filter driver 0 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb22fe20 name=Xen 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering Xen as driver 1 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb230de0 name=OPENVZ 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering OPENVZ as driver 2 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb231300 name=VMWARE 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering VMWARE as driver 3 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb2306c0 name=PHYP 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering PHYP as driver 4 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterStorageDriver:658 : registering PHYP as storage driver 1 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterInterfaceDriver:625 : registering PHYP as interface driver 1 2012-04-14 21:21:45.185+0000: 21338: debug : vboxRegister:137 : VBoxCGlueInit failed, using dummy driver 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb231820 name=VBOX 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering VBOX as driver 5 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterNetworkDriver:592 : registering VBOX as network driver 1 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterStorageDriver:658 : registering VBOX as storage driver 2 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb234800 name=ESX 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering ESX as driver 6 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterInterfaceDriver:625 : registering ESX as interface driver 2 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterNetworkDriver:592 : registering ESX as network driver 2 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterStorageDriver:658 : registering ESX as storage driver 3 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDeviceMonitor:691 : registering ESX as device driver 1 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterSecretDriver:724 : registering ESX as secret driver 1 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterNWFilterDriver:757 : registering ESX as network filter driver 1 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:775 : driver=0x7f16fb22f1c0 name=remote 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDriver:799 : registering remote as driver 7 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterNetworkDriver:592 : registering remote as network driver 3 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterInterfaceDriver:625 : registering remote as interface driver 3 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterStorageDriver:658 : registering remote as storage driver 4 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterDeviceMonitor:691 : registering remote as device driver 2 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterSecretDriver:724 : registering remote as secret driver 2 2012-04-14 21:21:45.185+0000: 21338: debug : virRegisterNWFilterDriver:757 : registering remote as network filter driver 2 2012-04-14 21:21:45.185+0000: 21338: debug : virEventRegisterDefaultImpl:204 : registering default event implementation 2012-04-14 21:21:45.185+0000: 21338: debug : virEventPollAddHandle:116 : Used 0 handle slots, adding at least 10 more 2012-04-14 21:21:45.185+0000: 21338: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 0 2012-04-14 21:21:45.185+0000: 21338: debug : virEventPollAddHandle:141 : EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x7f16fad71670 op 2012-04-14 21:21:45.185+0000: 21338: debug : virEventRegisterImpl:177 : addHandle=0x7f16fad72260 updateHandle=0x7f16fad72130 removeHandle=imeout=0x7f16fad71c50 updateTimeout=0x7f16fad71e20 removeTimeout=0x7f16fad71f50 2012-04-14 21:21:45.185+0000: 21338: debug : virConnectOpenAuth:1455 : name=(null), auth=0x7f16fb22e860, flags=1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventRunDefaultImpl:244 : running default event implementation 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:506 : Cleanup 0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:542 : Found 0 out of 0 timeout slots used, releasing 0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupHandles:554 : Cleanup 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 0 timers 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2012-04-14 21:21:45.186+0000: 21338: debug : virConnectGetDefaultURI:1105 : Using LIBVIRT_DEFAULT_URI 'qemu:///system' 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1182 : name "qemu:///system" to URI components:
  scheme qemu
  server (null)
  user (null)
  port 0
  path /system

2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 0 (Test) ... 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1232 : driver 0 Test returned DECLINED 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 1 (Xen) ... 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1232 : driver 1 Xen returned DECLINED 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 2 (OPENVZ) ... 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1232 : driver 2 OPENVZ returned DECLINED 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 3 (VMWARE) ... 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1232 : driver 3 VMWARE returned DECLINED 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 4 (PHYP) ... 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1232 : driver 4 PHYP returned DECLINED 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 5 (VBOX) ... 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1232 : driver 5 VBOX returned DECLINED 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 6 (ESX) ... 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1232 : driver 6 ESX returned DECLINED 2012-04-14 21:21:45.186+0000: 21338: debug : do_open:1226 : trying driver 7 (remote) ... 2012-04-14 21:21:45.186+0000: 21338: debug : doRemoteOpen:542 : proceeding with name = qemu:///system 2012-04-14 21:21:45.186+0000: 21338: debug : doRemoteOpen:552 : Connecting with transport 1 2012-04-14 21:21:45.186+0000: 21338: debug : doRemoteOpen:599 : Proceeding with sockname /var/run/libvirt/libvirt-sock-ro 2012-04-14 21:21:45.186+0000: 21338: debug : virNetSocketNew:119 : localAddr=0x7fff75e552a0 remoteAddr=0x7fff75e55210 fd=6 errfd 2012-04-14 21:21:45.186+0000: 21338: debug : virNetSocketNew:179 : RPC_SOCKET_NEW: sock=0x680f90 refs=1 fd=6 errfd=-1 pid=0 localAddr=127.=127.0.0.1;0 2012-04-14 21:21:45.186+0000: 21338: debug : virNetSocketRef:709 : RPC_SOCKET_REF: sock=0x680f90 refs=2 2012-04-14 21:21:45.186+0000: 21338: debug : virEventPollInterruptLocked:706 : Interrupting 2012-04-14 21:21:45.186+0000: 21338: debug : virEventPollAddHandle:141 : EVENT_POLL_ADD_HANDLE: watch=2 fd=6 events=1 cb=0x7f16fae700b0 op7f16fae707f0 2012-04-14 21:21:45.186+0000: 21338: debug : virKeepAliveNew:244 : client=0x7f16fb283010, interval=-1, count=0 2012-04-14 21:21:45.186+0000: 21338: debug : virEventPollAddTimeout:225 : Used 0 timeout slots, adding at least 10 more 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollRunOnce:630 : Poll got 1 event(s) 2012-04-14 21:21:45.186+0000: 21338: debug : virEventPollInterruptLocked:706 : Interrupting 2012-04-14 21:21:45.186+0000: 21338: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=-1 cb=0x7f16fae6c180 ox7f16fae6c3a0 2012-04-14 21:21:45.186+0000: 21338: debug : virKeepAliveNew:277 : RPC_KEEPALIVE_NEW: ka=0x680870 client=0x7f16fb283010 refs=2 2012-04-14 21:21:45.186+0000: 21338: debug : virNetClientNew:324 : RPC_CLIENT_NEW: client=0x7f16fb283010 refs=3 sock=0x680f9 2012-04-14 21:21:45.186+0000: 21338: debug : doRemoteOpen:684 : Trying authentication 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchTimeouts:415 : Dispatch 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:460 : Dispatch 1 2012-04-14 21:21:45.186+0000: 21338: debug : virNetMessageNew:48 : msg=0x7f16f43fb010 tracked=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:474 : i=0 w=1 2012-04-14 21:21:45.186+0000: 21338: debug : virNetMessageEncodePayload:351 : Encode length as 28 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:506 : Cleanup 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupHandles:554 : Cleanup 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventRunDefaultImpl:244 : running default event implementation 2012-04-14 21:21:45.186+0000: 21338: debug : virNetClientSendInternal:1675 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f16fb283010 len=28 prog=53=66 type=0 status=0 serial=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:506 : Cleanup 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupHandles:554 : Cleanup 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=1 d=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 timeout=-1 2012-04-14 21:21:45.186+0000: 21338: debug : virNetClientIO:1533 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 lengt 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollRunOnce:630 : Poll got 1 event(s) 2012-04-14 21:21:45.186+0000: 21338: debug : virNetClientIO:1591 : We have the buck 0x6822d0 0x6822d0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchTimeouts:415 : Dispatch 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:460 : Dispatch 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:474 : i=0 w=1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2012-04-14 21:21:45.186+0000: 21338: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:474 : i=1 w=2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:506 : Cleanup 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupHandles:554 : Cleanup 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventRunDefaultImpl:244 : running default event implementation 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:506 : Cleanup 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupHandles:554 : Cleanup 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=1 d=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 timeout=-1 2012-04-14 21:21:45.186+0000: 21338: debug : virEventPollInterruptLocked:706 : Interrupting 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollRunOnce:630 : Poll got 1 event(s) 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchTimeouts:415 : Dispatch 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:460 : Dispatch 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:474 : i=0 w=1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:506 : Cleanup 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupHandles:554 : Cleanup 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventRunDefaultImpl:244 : running default event implementation 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupTimeouts:506 : Cleanup 1 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCleanupHandles:554 : Cleanup 2 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms 2012-04-14 21:21:45.186+0000: 21339: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 timeout=-1

uname -a
Linux f37.local 3.3.1-std-def-alt1 #1 SMP Tue Apr 10 13:27:26 UTC 2012 x86_64 GNU/Linux

libvirtd --version
libvirtd (libvirt) 0.9.11


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]