[Let's keep it on the list, so other could help too] 2010/3/15 Anthony Lannuzel <lannuzel@gmail.com>:

On Sat, Mar 13, 2010 at 6:51 PM, Matthias Bolte <matthias.bolte@googlemail.com> wrote:

...

2010/3/13 Anthony Lannuzel <lannuzel@gmail.com>:

...

Hi,

I'm having an issue when trying to start a (previously created) vbox item : virsh gets stucked in virDomainCreate and I see no error message (LIBVIRT_DEBUG=1). Is there any mean to get more information on what is happening ?

Moreover, now that virsh has stalled, running "connect vbox:///session" on another virsh instance gets an error from "secret driver". Is this normal, as if I'm only supposed to have 1 connection at a time ?

Thanks Regards

Anthony

I tested starting vbox guest using virsh and it works as expected and I can use multiple connections at the same time as expected.

What libvirt and vbox versions do you use?

Can you give some more details about what you did to trigger this problem?

Matthias

Hi,

I'm using virsh 0.7.6 with VirtualBox 3.1.4 on a 2.6.24 kernel with openVZ, unionfs and squashfs patches.

Here is what I do :

The domain is created with virDomainDefineXML. Here is the XML file content:

<domain type="vbox">  <name>c7c0ab9f-9a19-4a45-92a1-799367789509</name>  <uuid>c7c0ab9f-9a19-4a45-92a1-799367789509</uuid>  <vcpu>1</vcpu>  <memory>196608</memory>  <on_poweroff>destroy</on_poweroff>  <on_reboot>destroy</on_reboot>  <on_crash>destroy</on_crash>  <os>    <type>hvm</type>  </os>  <features>    <pae></pae>    <acpi></acpi>    <apic></apic>  </features>  <devices>    <disk device="disk" type="file">      <source file="/data/c7c0ab9f-9a19-4a45-92a1-799367789509/ubuntuDesktop-8.04.vdi"/>      <target bus="ide" dev="hda"/>    </disk>    <interface type="bridge">      <source bridge="hnsTap0_tap"/>      <mac address="00:22:94:ae:a1:86"/>      <model type="82543gc"/>    </interface>    <graphics port="12000" type="rdp"/>  </devices> </domain>

Then I try to start it with virsh:

root@hynesim-live:/home/hynesim# virsh 10:09:06.685: debug : virInitialize:336 : register drivers 10:09:06.685: debug : virRegisterDriver:837 : registering Test as driver 0 10:09:06.685: debug : virRegisterNetworkDriver:675 : registering Test as network driver 0 10:09:06.685: debug : virRegisterInterfaceDriver:706 : registering Test as interface driver 0 10:09:06.685: debug : virRegisterStorageDriver:737 : registering Test as storage driver 0 10:09:06.685: debug : virRegisterDeviceMonitor:768 : registering Test as device driver 0 10:09:06.685: debug : virRegisterSecretDriver:799 : registering Test as secret driver 0 10:09:06.685: debug : virRegisterDriver:837 : registering OPENVZ as driver 1 10:09:06.709: debug : vboxRegister:87 : VBoxCGlueInit found API version: 3.1.4 (3001004) 10:09:06.718: debug : vboxRegister:104 : VirtualBox API version: 3.1 10:09:06.718: debug : virRegisterDriver:837 : registering VBOX as driver 2 10:09:06.718: debug : virRegisterNetworkDriver:675 : registering VBOX as network driver 1 10:09:06.718: debug : virRegisterStorageDriver:737 : registering VBOX as storage driver 1 10:09:06.718: debug : virRegisterDriver:837 : registering remote as driver 3 10:09:06.718: debug : virRegisterNetworkDriver:675 : registering remote as network driver 2 10:09:06.719: debug : virRegisterInterfaceDriver:706 : registering remote as interface driver 1 10:09:06.719: debug : virRegisterStorageDriver:737 : registering remote as storage driver 2 10:09:06.719: debug : virRegisterDeviceMonitor:768 : registering remote as device driver 1 10:09:06.719: debug : virRegisterSecretDriver:799 : registering remote as secret driver 1 10:09:06.719: debug : virConnectOpenAuth:1355 : name=(null), auth=0x2b78d7561c80, flags=0 10:09:06.719: debug : do_open:1112 : no name, allowing driver auto-select 10:09:06.719: debug : do_open:1120 : trying driver 0 (Test) ... 10:09:06.719: debug : do_open:1126 : driver 0 Test returned DECLINED 10:09:06.719: debug : do_open:1120 : trying driver 1 (OPENVZ) ... 10:09:06.759: debug : virExecWithHook:637 : LC_ALL=C /usr/sbin/vzctl --help 10:09:06.771: debug : do_open:1126 : driver 1 OPENVZ returned SUCCESS 10:09:06.771: debug : do_open:1146 : network driver 0 Test returned DECLINED 10:09:06.771: debug : do_open:1146 : network driver 1 VBOX returned DECLINED 10:09:06.772: debug : doRemoteOpen:564 : proceeding with name = openvz:///system 10:09:06.774: debug : remoteIO:8429 : Do proc=66 serial=0 length=28 wait=(nil) 10:09:06.774: debug : remoteIO:8491 : We have the buck 66 0x2b78dbcf2010 0x2b78dbcf2010 10:09:06.776: debug : remoteIODecodeMessageLength:7913 : Got length, now need 64 total (60 more) 10:09:06.776: debug : remoteIOEventLoop:8355 : Giving up the buck 66 0x2b78dbcf2010 (nil) 10:09:06.776: debug : remoteIO:8522 : All done with our call 66 (nil) 0x2b78dbcf2010 10:09:06.776: debug : remoteIO:8429 : Do proc=1 serial=1 length=56 wait=(nil) 10:09:06.776: debug : remoteIO:8491 : We have the buck 1 0x63fe50 0x63fe50 10:09:06.848: debug : remoteIODecodeMessageLength:7913 : Got length, now need 56 total (52 more) 10:09:06.848: debug : remoteIOEventLoop:8355 : Giving up the buck 1 0x63fe50 (nil) 10:09:06.848: debug : remoteIO:8522 : All done with our call 1 (nil) 0x63fe50 10:09:06.848: debug : doRemoteOpen:891 : Adding Handler for remote events 10:09:06.848: debug : doRemoteOpen:898 : virEventAddHandle failed: No addHandleImpl defined. continuing without events. 10:09:06.848: debug : do_open:1146 : network driver 2 remote returned SUCCESS 10:09:06.848: debug : do_open:1165 : interface driver 0 Test returned DECLINED 10:09:06.849: debug : doRemoteOpen:564 : proceeding with name = openvz:///system 10:09:06.850: debug : remoteIO:8429 : Do proc=66 serial=0 length=28 wait=(nil) 10:09:06.850: debug : remoteIO:8491 : We have the buck 66 0x67ff00 0x67ff00 10:09:06.852: debug : remoteIODecodeMessageLength:7913 : Got length, now need 64 total (60 more) 10:09:06.852: debug : remoteIOEventLoop:8355 : Giving up the buck 66 0x67ff00 (nil) 10:09:06.852: debug : remoteIO:8522 : All done with our call 66 (nil) 0x67ff00 10:09:06.853: debug : remoteIO:8429 : Do proc=1 serial=1 length=56 wait=(nil) 10:09:06.853: debug : remoteIO:8491 : We have the buck 1 0x67ff00 0x67ff00 10:09:06.901: debug : remoteIODecodeMessageLength:7913 : Got length, now need 56 total (52 more) 10:09:06.901: debug : remoteIOEventLoop:8355 : Giving up the buck 1 0x67ff00 (nil) 10:09:06.901: debug : remoteIO:8522 : All done with our call 1 (nil) 0x67ff00 10:09:06.901: debug : doRemoteOpen:891 : Adding Handler for remote events 10:09:06.901: debug : doRemoteOpen:898 : virEventAddHandle failed: No addHandleImpl defined. continuing without events. 10:09:06.901: debug : do_open:1165 : interface driver 1 remote returned SUCCESS 10:09:06.901: debug : do_open:1185 : storage driver 0 Test returned DECLINED 10:09:06.901: debug : do_open:1185 : storage driver 1 VBOX returned DECLINED 10:09:06.901: debug : do_open:1185 : storage driver 2 remote returned SUCCESS 10:09:06.901: debug : do_open:1205 : node driver 0 Test returned DECLINED 10:09:06.901: debug : do_open:1205 : node driver 1 remote returned SUCCESS 10:09:06.901: debug : do_open:1232 : secret driver 0 Test returned DECLINED 10:09:06.901: debug : do_open:1232 : secret driver 1 remote returned SUCCESS Bienvenue dans virsh, le terminal de virtualisation interactif.

Taper :  « help » pour l'aide ou « help » avec la commande         « quit » pour quitter

virsh # connect vbox:///session 10:09:13.993: debug : virConnectClose:1381 : conn=0x63b060 10:09:13.994: debug : virUnrefConnect:259 : unref connection 0x63b060 1 10:09:13.994: debug : remoteIO:8429 : Do proc=2 serial=2 length=28 wait=(nil) 10:09:13.994: debug : remoteIO:8491 : We have the buck 2 0x680170 0x680170 10:09:13.995: debug : remoteIODecodeMessageLength:7913 : Got length, now need 56 total (52 more) 10:09:13.995: debug : remoteIOEventLoop:8355 : Giving up the buck 2 0x680170 (nil) 10:09:13.995: debug : remoteIO:8522 : All done with our call 2 (nil) 0x680170 10:09:13.996: debug : remoteIO:8429 : Do proc=2 serial=2 length=28 wait=(nil) 10:09:13.996: debug : remoteIO:8491 : We have the buck 2 0x680170 0x680170 10:09:13.997: debug : remoteIODecodeMessageLength:7913 : Got length, now need 56 total (52 more) 10:09:13.997: debug : remoteIOEventLoop:8355 : Giving up the buck 2 0x680170 (nil) 10:09:13.997: debug : remoteIO:8522 : All done with our call 2 (nil) 0x680170 10:09:13.997: debug : virDomainObjUnref:680 : obj=0x63ebf0 refs=0 10:09:13.997: debug : virDomainObjFree:658 : obj=0x63ebf0 10:09:13.997: debug : virReleaseConnect:216 : release connection 0x63b060 10:09:13.997: debug : virConnectOpenAuth:1355 : name=vbox:///session, auth=0x2b78d7561c80, flags=0 10:09:13.997: debug : do_open:1110 : name "vbox:///session" to URI components:  scheme vbox  opaque (null)  authority (null)  server (null)  user (null)  port 0  path /session

10:09:13.997: debug : do_open:1120 : trying driver 0 (Test) ... 10:09:13.997: debug : do_open:1126 : driver 0 Test returned DECLINED 10:09:13.997: debug : do_open:1120 : trying driver 1 (OPENVZ) ... 10:09:13.997: debug : do_open:1126 : driver 1 OPENVZ returned DECLINED 10:09:13.997: debug : do_open:1120 : trying driver 2 (VBOX) ... 10:09:14.021: debug : vboxOpen:836 : in vboxOpen 10:09:14.021: debug : do_open:1126 : driver 2 VBOX returned SUCCESS 10:09:14.021: debug : do_open:1146 : network driver 0 Test returned DECLINED 10:09:14.021: debug : vboxNetworkOpen:5434 : network initialized 10:09:14.021: debug : do_open:1146 : network driver 1 VBOX returned SUCCESS 10:09:14.022: debug : do_open:1165 : interface driver 0 Test returned DECLINED 10:09:14.022: debug : doRemoteOpen:564 : proceeding with name = vbox:///session 10:09:14.024: debug : remoteIO:8429 : Do proc=66 serial=0 length=28 wait=(nil) 10:09:14.024: debug : remoteIO:8491 : We have the buck 66 0x6eaa90 0x6eaa90 10:09:14.025: debug : remoteIODecodeMessageLength:7913 : Got length, now need 64 total (60 more) 10:09:14.025: debug : remoteIOEventLoop:8355 : Giving up the buck 66 0x6eaa90 (nil) 10:09:14.025: debug : remoteIO:8522 : All done with our call 66 (nil) 0x6eaa90 10:09:14.026: debug : remoteIO:8429 : Do proc=1 serial=1 length=56 wait=(nil) 10:09:14.026: debug : remoteIO:8491 : We have the buck 1 0x6eaa90 0x6eaa90 10:09:14.027: debug : remoteIODecodeMessageLength:7913 : Got length, now need 56 total (52 more) 10:09:14.027: debug : remoteIOEventLoop:8355 : Giving up the buck 1 0x6eaa90 (nil) 10:09:14.027: debug : remoteIO:8522 : All done with our call 1 (nil) 0x6eaa90 10:09:14.027: debug : doRemoteOpen:891 : Adding Handler for remote events 10:09:14.027: debug : doRemoteOpen:898 : virEventAddHandle failed: No addHandleImpl defined. continuing without events. 10:09:14.027: debug : do_open:1165 : interface driver 1 remote returned SUCCESS 10:09:14.027: debug : do_open:1185 : storage driver 0 Test returned DECLINED 10:09:14.027: debug : vboxStorageOpen:6186 : vbox storage initialized 10:09:14.027: debug : do_open:1185 : storage driver 1 VBOX returned SUCCESS 10:09:14.028: debug : do_open:1205 : node driver 0 Test returned DECLINED 10:09:14.028: debug : doRemoteOpen:564 : proceeding with name = vbox:///session 10:09:14.030: debug : remoteIO:8429 : Do proc=66 serial=0 length=28 wait=(nil) 10:09:14.037: debug : remoteIO:8491 : We have the buck 66 0x72ab40 0x72ab40 10:09:14.038: debug : remoteIODecodeMessageLength:7913 : Got length, now need 64 total (60 more) 10:09:14.038: debug : remoteIOEventLoop:8355 : Giving up the buck 66 0x72ab40 (nil) 10:09:14.038: debug : remoteIO:8522 : All done with our call 66 (nil) 0x72ab40 10:09:14.038: debug : remoteIO:8429 : Do proc=1 serial=1 length=56 wait=(nil) 10:09:14.039: debug : remoteIO:8491 : We have the buck 1 0x72ab40 0x72ab40 10:09:14.040: debug : remoteIODecodeMessageLength:7913 : Got length, now need 56 total (52 more) 10:09:14.040: debug : remoteIOEventLoop:8355 : Giving up the buck 1 0x72ab40 (nil) 10:09:14.040: debug : remoteIO:8522 : All done with our call 1 (nil) 0x72ab40 10:09:14.040: debug : doRemoteOpen:891 : Adding Handler for remote events 10:09:14.040: debug : doRemoteOpen:898 : virEventAddHandle failed: No addHandleImpl defined. continuing without events. 10:09:14.040: debug : do_open:1205 : node driver 1 remote returned SUCCESS 10:09:14.040: debug : do_open:1232 : secret driver 0 Test returned DECLINED 10:09:14.040: debug : doRemoteOpen:564 : proceeding with name = vbox:///session 10:09:14.041: debug : remoteIO:8429 : Do proc=66 serial=0 length=28 wait=(nil) 10:09:14.041: debug : remoteIO:8491 : We have the buck 66 0x76abf0 0x76abf0 10:09:14.042: debug : remoteIODecodeMessageLength:7913 : Got length, now need 64 total (60 more) 10:09:14.042: debug : remoteIOEventLoop:8355 : Giving up the buck 66 0x76abf0 (nil) 10:09:14.042: debug : remoteIO:8522 : All done with our call 66 (nil) 0x76abf0 10:09:14.043: debug : remoteIO:8429 : Do proc=1 serial=1 length=56 wait=(nil) 10:09:14.043: debug : remoteIO:8491 : We have the buck 1 0x76abf0 0x76abf0 10:09:14.044: debug : remoteIODecodeMessageLength:7913 : Got length, now need 56 total (52 more) 10:09:14.044: debug : remoteIOEventLoop:8355 : Giving up the buck 1 0x76abf0 (nil) 10:09:14.044: debug : remoteIO:8522 : All done with our call 1 (nil) 0x76abf0 10:09:14.044: debug : doRemoteOpen:891 : Adding Handler for remote events 10:09:14.044: debug : doRemoteOpen:898 : virEventAddHandle failed: No addHandleImpl defined. continuing without events. 10:09:14.044: debug : do_open:1232 : secret driver 1 remote returned SUCCESS

virsh # list --all 10:09:19.563: debug : virConnectNumOfDomains:1749 : conn=0x63ebf0 10:09:19.568: debug : virConnectNumOfDefinedDomains:4609 : conn=0x63ebf0 10:09:19.568: debug : virConnectListDefinedDomains:4648 : conn=0x63ebf0, names=0x692430, maxnames=1  ID Nom                  État ---------------------------------- 10:09:19.570: debug : virDomainLookupByName:2010 : conn=0x63ebf0, name=c7c0ab9f-9a19-4a45-92a1-799367789509 10:09:19.571: debug : virGetDomain:345 : New hash entry 0x6a6000 10:09:19.571: debug : virDomainGetInfo:2867 : domain=0x6a6000, info=0x7fffd3a519e0  - c7c0ab9f-9a19-4a45-92a1-799367789509 closed 10:09:19.573: debug : virDomainFree:2098 : domain=0x6a6000 10:09:19.573: debug : virUnrefDomain:422 : unref domain 0x6a6000 c7c0ab9f-9a19-4a45-92a1-799367789509 1 10:09:19.573: debug : virReleaseDomain:376 : release domain 0x6a6000 c7c0ab9f-9a19-4a45-92a1-799367789509 10:09:19.573: debug : virReleaseDomain:392 : unref connection 0x63ebf0 2

virsh # start c7c0ab9f-9a19-4a45-92a1-799367789509 10:09:26.108: debug : virDomainLookupByName:2010 : conn=0x63ebf0, name=c7c0ab9f-9a19-4a45-92a1-799367789509 10:09:26.112: debug : virGetDomain:345 : New hash entry 0x68bd70 10:09:26.112: debug : virDomainGetID:2658 : domain=0x68bd70 10:09:26.112: debug : virDomainCreate:4690 : domain=0x68bd70 10:09:26.112: debug : virDomainCreate:4693 : 1 0x68bd70 10:09:26.112: debug : virDomainCreate:4700 : 2 0x68bd70 10:09:26.112: debug : virDomainCreate:4707 : 3 0x68bd70 10:09:26.112: debug : virDomainCreate:4710 : 3.1 0x68bd70 10:09:26.223: debug : vboxDomainCreate:3321 : before close 0x68bd70

I have added some debug lines, that lead to:

in libvirt.c: function int virDomainCreate(virDomainPtr domain)        ret = conn->driver->domainCreate (domain); // does not return

in vbox/vbox_tmpl.c: function static int vboxDomainCreate(virDomainPtr dom)                    data->vboxSession->vtbl->Close(data->vboxSession); // does not return

Thanks

At that point the domain should already be running. I wonder why closing the session handle would block. You could try variations of the domain XML config, assuming that a specify part of the config triggers this problem. For example use your posted domain XML config, but leave out the graphics part or the interface part or the disk part to see if that makes a difference. Matthias