[libvirt] saving domains causes stucks all other commands

Sat Nov 28 15:45:40 UTC 2009

Hi,
I noticed that using libvirt to save running KVM domain (ie using virsh save ...)
causes all other attempts to connect to libvirt and do something to hang till
the save finishes. Seems like the issue has been already reported once:
http://www.mail-archive.com/libvir-list@redhat.com/msg11431.html
but without any resoulution. 
I've tried libvirt-0.7.4 + also applied bb8d57c68a5d9601058692813c7bdaf83c3d3aff
(Fix threading problems in python bindings) which seemed to me might be related
but still the problem persists.

here's the debug log of trying to list domains while saving some domain:
[root at vbox3 ~]# virsh list
16:30:31.718: debug : virInitialize:278 : register drivers
16:30:31.718: debug : virRegisterDriver:779 : registering Test as driver 0
16:30:31.718: debug : virRegisterNetworkDriver:617 : registering Test as network driver 0
16:30:31.718: debug : virRegisterInterfaceDriver:648 : registering Test as interface driver 0
16:30:31.718: debug : virRegisterStorageDriver:679 : registering Test as storage driver 0
16:30:31.718: debug : virRegisterDeviceMonitor:710 : registering Test as device driver 0
16:30:31.718: debug : virRegisterSecretDriver:741 : registering Test as secret driver 0
16:30:31.718: debug : vboxRegister:101 : VBoxCGlueInit failed, using dummy driver
16:30:31.718: debug : virRegisterDriver:779 : registering VBOX as driver 1
16:30:31.718: debug : virRegisterNetworkDriver:617 : registering VBOX as network driver 1
16:30:31.718: debug : virRegisterStorageDriver:679 : registering VBOX as storage driver 1
16:30:31.718: debug : virRegisterDriver:779 : registering remote as driver 2
16:30:31.718: debug : virRegisterNetworkDriver:617 : registering remote as network driver 2
16:30:31.718: debug : virRegisterInterfaceDriver:648 : registering remote as interface driver 1
16:30:31.718: debug : virRegisterStorageDriver:679 : registering remote as storage driver 2
16:30:31.718: debug : virRegisterDeviceMonitor:710 : registering remote as device driver 1
16:30:31.718: debug : virRegisterSecretDriver:741 : registering remote as secret driver 1
16:30:31.718: debug : virConnectOpenAuth:1279 : name=(null), auth=0x7f89bc41b8a0, flags=0
16:30:31.718: debug : do_open:1050 : no name, allowing driver auto-select
16:30:31.718: debug : do_open:1058 : trying driver 0 (Test) ...
16:30:31.718: debug : do_open:1064 : driver 0 Test returned DECLINED
16:30:31.718: debug : do_open:1058 : trying driver 1 (VBOX) ...
16:30:31.718: debug : do_open:1064 : driver 1 VBOX returned DECLINED
16:30:31.718: debug : do_open:1058 : trying driver 2 (remote) ...
16:30:31.718: debug : remoteOpen:1064 : Auto-probe remote URI
16:30:31.718: debug : doRemoteOpen:564 : proceeding with name =
16:30:31.719: debug : remoteIO:8359 : Do proc=66 serial=0 length=28 wait=(nil)
16:30:31.719: debug : remoteIO:8421 : We have the buck 66 0x7f89bc5b5010 0x7f89bc5b5010
16:30:31.720: debug : remoteIODecodeMessageLength:7843 : Got length, now need 64 total (60 more)
16:30:31.720: debug : remoteIOEventLoop:8285 : Giving up the buck 66 0x7f89bc5b5010 (nil)
16:30:31.720: debug : remoteIO:8452 : All done with our call 66 (nil) 0x7f89bc5b5010
16:30:31.720: debug : remoteIO:8359 : Do proc=1 serial=1 length=40 wait=(nil)
16:30:31.720: debug : remoteIO:8421 : We have the buck 1 0x256ce90 0x256ce90
16:30:31.721: debug : remoteIODecodeMessageLength:7843 : Got length, now need 56 total (52 more)
16:30:31.722: debug : remoteIOEventLoop:8285 : Giving up the buck 1 0x256ce90 (nil)
16:30:31.722: debug : remoteIO:8452 : All done with our call 1 (nil) 0x256ce90
16:30:31.722: debug : remoteIO:8359 : Do proc=110 serial=2 length=28 wait=(nil)
16:30:31.722: debug : remoteIO:8421 : We have the buck 110 0x256ce90 0x256ce90
16:30:31.723: debug : remoteIODecodeMessageLength:7843 : Got length, now need 76 total (72 more)
16:30:31.723: debug : remoteIOEventLoop:8285 : Giving up the buck 110 0x256ce90 (nil)
16:30:31.723: debug : remoteIO:8452 : All done with our call 110 (nil) 0x256ce90
16:30:31.723: debug : doRemoteOpen:872 : Auto-probed URI is qemu:///system
16:30:31.723: debug : doRemoteOpen:891 : Adding Handler for remote events
16:30:31.723: debug : doRemoteOpen:898 : virEventAddHandle failed: No addHandleImpl defined. continuing without events.
16:30:31.723: debug : do_open:1064 : driver 2 remote returned SUCCESS
16:30:31.723: debug : do_open:1084 : network driver 0 Test returned DECLINED
16:30:31.723: debug : do_open:1084 : network driver 1 VBOX returned DECLINED
16:30:31.723: debug : do_open:1084 : network driver 2 remote returned SUCCESS
16:30:31.723: debug : do_open:1103 : interface driver 0 Test returned DECLINED
16:30:31.723: debug : do_open:1103 : interface driver 1 remote returned SUCCESS
16:30:31.723: debug : do_open:1123 : storage driver 0 Test returned DECLINED
16:30:31.723: debug : do_open:1123 : storage driver 1 VBOX returned DECLINED
16:30:31.723: debug : do_open:1123 : storage driver 2 remote returned SUCCESS
16:30:31.723: debug : do_open:1143 : node driver 0 Test returned DECLINED
16:30:31.723: debug : do_open:1143 : node driver 1 remote returned SUCCESS
16:30:31.723: debug : do_open:1170 : secret driver 0 Test returned DECLINED
16:30:31.723: debug : do_open:1170 : secret driver 1 remote returned SUCCESS
16:30:31.723: debug : virConnectNumOfDomains:1656 : conn=0x2569c30
16:30:31.723: debug : remoteIO:8359 : Do proc=51 serial=3 length=28 wait=(nil)
16:30:31.723: debug : remoteIO:8421 : We have the buck 51 0x256ced0 0x256ced0
.. (here's the long wait till save finishes)..

16:31:11.077: debug : remoteIODecodeMessageLength:7843 : Got length, now need 60 total (56 more)
16:31:11.077: debug : remoteIOEventLoop:8285 : Giving up the buck 51 0x256ced0 (nil)
16:31:11.077: debug : remoteIO:8452 : All done with our call 51 (nil) 0x256ced0
 Id Name                 State
----------------------------------

16:31:11.077: debug : virConnectClose:1297 : conn=0x2569c30
16:31:11.077: debug : virUnrefConnect:259 : unref connection 0x2569c30 1
16:31:11.077: debug : remoteIO:8359 : Do proc=2 serial=4 length=28 wait=(nil)
16:31:11.077: debug : remoteIO:8421 : We have the buck 2 0x256d0e0 0x256d0e0
16:31:11.079: debug : remoteIODecodeMessageLength:7843 : Got length, now need 56 total (52 more)
16:31:11.079: debug : remoteIOEventLoop:8285 : Giving up the buck 2 0x256d0e0 (nil)
16:31:11.079: debug : remoteIO:8452 : All done with our call 2 (nil) 0x256d0e0
16:31:11.079: debug : virReleaseConnect:216 : release connection 0x2569c30

Could somebody please have a look on this issue? I'll gladly provide any help if I'll
be able.

thanks a lot in advance!

with best regards

nik

-- 
-------------------------------------
Nikola CIPRICH
LinuxBox.cz, s.r.o.
28. rijna 168, 709 01 Ostrava

tel.:   +420 596 603 142
fax:    +420 596 621 273
mobil:  +420 777 093 799

www.linuxbox.cz

mobil servis: +420 737 238 656
email servis: servis at linuxbox.cz
-------------------------------------