[libvirt] VBOX driver : "An error occurred, but the cause is unknown" when trying to start a Virtualbox domain

Jean-Christophe Guillain jc.guillain at gmail.com
Mon Nov 28 11:25:58 UTC 2011 

Hello,

I opened a bug (http://bugzilla.redhat.com/show_bug.cgi?id=757138)
about this issue, but I was told to mention it to this list too.

Here is my problem : when I try to start a virtualbox domain with
virsh, an error occurs.
(But when the domain is started using Virtualbox GUI it works, and I have no
problem to stop it with virsh...)

Example :

virsh # start freenas1
error: Failed to start domain freenas1
error: An error occurred, but the cause is unknown

I use libvirt 0.9.2-7 and virtualbox 4.0.10 on a Debian with
2.6.32-5-amd64 kernel.

The XML config file of the domain :

<domain type='vbox' id='1'>
  <name>freenas1</name>
  <uuid>07aadf11-2090-4690-9518-52766722c544</uuid>
  <memory>524288</memory>
  <currentMemory>524288</currentMemory>
  <vcpu>1</vcpu>
  <os>
    <type arch='x86_64'>hvm</type>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <clock offset='localtime'/>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>destroy</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <disk type='file' device='disk'>
      <source file='/data/Freenas1Disk1.vdi'/>
      <target dev='hda' bus='ide'/>
    </disk>
    <input type='mouse' bus='ps2'/>
    <graphics type='desktop' display='localhost:10.0'/>
    <video>
      <model type='vbox' vram='8192' heads='1'>
        <acceleration accel3d='no' accel2d='no'/>
      </model>
    </video>
  </devices>
</domain>


virsh debug output :

virsh # start freenas1
15:51:31.043: 5796: debug : virConnectOpenAuth:1328 : name=(null),
auth=0x7f19ee32d320, flags=0
15:51:31.043: 5796: debug : do_open:1065 : no name, allowing driver auto-select
15:51:31.043: 5796: debug : do_open:1102 : trying driver 0 (Test) ...
15:51:31.043: 5796: debug : do_open:1108 : driver 0 Test returned DECLINED
15:51:31.043: 5796: debug : do_open:1102 : trying driver 1 (Xen) ...
15:51:31.043: 5796: debug : do_open:1108 : driver 1 Xen returned DECLINED
15:51:31.043: 5796: debug : do_open:1102 : trying driver 2 (OPENVZ) ...
15:51:31.043: 5796: debug : do_open:1108 : driver 2 OPENVZ returned DECLINED
15:51:31.043: 5796: debug : do_open:1102 : trying driver 3 (VMWARE) ...
15:51:31.043: 5796: debug : do_open:1108 : driver 3 VMWARE returned DECLINED
15:51:31.043: 5796: debug : do_open:1102 : trying driver 4 (VBOX) ...
15:51:31.050: 5796: debug : vboxOpen:1035 : in vboxOpen
15:51:31.050: 5796: debug : do_open:1108 : driver 4 VBOX returned SUCCESS
15:51:31.050: 5796: debug : do_open:1130 : network driver 0 Test returned
DECLINED
15:51:31.050: 5796: debug : vboxNetworkOpen:6953 : network initialized
15:51:31.050: 5796: debug : do_open:1130 : network driver 1 VBOX returned
SUCCESS
15:51:31.050: 5796: debug : do_open:1145 : interface driver 0 Test returned
DECLINED
15:51:31.051: 5796: debug : doRemoteOpen:596 : proceeding with name =
vbox:///system
15:51:31.051: 5796: debug : remoteIO:5824 : Do proc=66 serial=0 length=28
wait=(nil)
15:51:31.051: 5796: debug : remoteIO:5896 : We have the buck 66 0x7f19e6c37010
0x7f19e6c37010
15:51:31.051: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 64 total (60 more)
15:51:31.051: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 66
0x7f19e6c37010 (nil)
15:51:31.051: 5796: debug : remoteIO:5924 : All done with our call 66 (nil)
0x7f19e6c37010
15:51:31.051: 5796: debug : remoteIO:5824 : Do proc=1 serial=1 length=56
wait=(nil)
15:51:31.051: 5796: debug : remoteIO:5896 : We have the buck 1 0x7f19e003fec0
0x7f19e003fec0
15:51:31.052: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 176 total (172 more)
15:51:31.052: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 1
0x7f19e003fec0 (nil)
15:51:31.052: 5796: debug : remoteIO:5924 : All done with our call 1 (nil)
0x7f19e003fec0
15:51:31.052: 5796: debug : do_open:1145 : interface driver 1 remote returned
ERROR
15:51:31.052: 5796: debug : do_open:1161 : storage driver 0 Test returned
DECLINED
15:51:31.052: 5796: debug : vboxStorageOpen:7764 : vbox storage initialized
15:51:31.052: 5796: debug : do_open:1161 : storage driver 1 VBOX returned
SUCCESS
15:51:31.052: 5796: debug : do_open:1177 : node driver 0 Test returned DECLINED
15:51:31.053: 5796: debug : doRemoteOpen:596 : proceeding with name =
vbox:///system
15:51:31.053: 5796: debug : remoteIO:5824 : Do proc=66 serial=0 length=28
wait=(nil)
15:51:31.053: 5796: debug : remoteIO:5896 : We have the buck 66 0x7f19e0081f90
0x7f19e0081f90
15:51:31.054: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 64 total (60 more)
15:51:31.054: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 66
0x7f19e0081f90 (nil)
15:51:31.054: 5796: debug : remoteIO:5924 : All done with our call 66 (nil)
0x7f19e0081f90
15:51:31.054: 5796: debug : remoteIO:5824 : Do proc=1 serial=1 length=56
wait=(nil)
15:51:31.054: 5796: debug : remoteIO:5896 : We have the buck 1 0x7f19e0081f90
0x7f19e0081f90
15:51:31.055: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 176 total (172 more)
15:51:31.055: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 1
0x7f19e0081f90 (nil)
15:51:31.055: 5796: debug : remoteIO:5924 : All done with our call 1 (nil)
0x7f19e0081f90
15:51:31.055: 5796: debug : do_open:1177 : node driver 1 remote returned ERROR
15:51:31.055: 5796: debug : do_open:1193 : secret driver 0 Test returned
DECLINED
15:51:31.055: 5796: debug : doRemoteOpen:596 : proceeding with name =
vbox:///system
15:51:31.055: 5796: debug : remoteIO:5824 : Do proc=66 serial=0 length=28
wait=(nil)
15:51:31.055: 5796: debug : remoteIO:5896 : We have the buck 66 0x7f19e0081f90
0x7f19e0081f90
15:51:31.056: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 64 total (60 more)
15:51:31.056: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 66
0x7f19e0081f90 (nil)
15:51:31.056: 5796: debug : remoteIO:5924 : All done with our call 66 (nil)
0x7f19e0081f90
15:51:31.056: 5796: debug : remoteIO:5824 : Do proc=1 serial=1 length=56
wait=(nil)
15:51:31.056: 5796: debug : remoteIO:5896 : We have the buck 1 0x7f19e0081f90
0x7f19e0081f90
15:51:31.057: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 176 total (172 more)
15:51:31.057: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 1
0x7f19e0081f90 (nil)
15:51:31.057: 5796: debug : remoteIO:5924 : All done with our call 1 (nil)
0x7f19e0081f90
15:51:31.057: 5796: debug : do_open:1193 : secret driver 1 remote returned
ERROR
15:51:31.057: 5796: debug : do_open:1209 : nwfilter driver 0 Test returned
DECLINED
15:51:31.057: 5796: debug : doRemoteOpen:596 : proceeding with name =
vbox:///system
15:51:31.057: 5796: debug : remoteIO:5824 : Do proc=66 serial=0 length=28
wait=(nil)
15:51:31.057: 5796: debug : remoteIO:5896 : We have the buck 66 0x7f19e0081f90
0x7f19e0081f90
15:51:31.058: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 64 total (60 more)
15:51:31.058: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 66
0x7f19e0081f90 (nil)
15:51:31.058: 5796: debug : remoteIO:5924 : All done with our call 66 (nil)
0x7f19e0081f90
15:51:31.058: 5796: debug : remoteIO:5824 : Do proc=1 serial=1 length=56
wait=(nil)
15:51:31.058: 5796: debug : remoteIO:5896 : We have the buck 1 0x7f19e0081f90
0x7f19e0081f90
15:51:31.059: 5796: debug : remoteIODecodeMessageLength:5214 : Got length, now
need 176 total (172 more)
15:51:31.059: 5796: debug : remoteIOEventLoop:5750 : Giving up the buck 1
0x7f19e0081f90 (nil)
15:51:31.059: 5796: debug : remoteIO:5924 : All done with our call 1 (nil)
0x7f19e0081f90
15:51:31.059: 5796: debug : do_open:1209 : nwfilter driver 1 remote returned
ERROR
15:51:31.060: 5796: debug : virDomainLookupByName:2030 : conn=0x6f6350,
name=freenas1
15:51:31.061: 5796: debug : virDomainGetID:2718 : dom=0x7f19e002db00, (VM:
name=freenas1, uuid=07aadf11-2090-4690-9518-52766722c544),
15:51:31.061: 5796: debug : virDomainCreate:6300 : dom=0x7f19e002db00, (VM:
name=freenas1, uuid=07aadf11-2090-4690-9518-52766722c544),
15:51:31.566: 5796: debug : virDomainGetName:2623 : domain=0x7f19e002db00
error: Failed to start domain freenas1
15:51:31.566: 5796: debug : virDomainFree:2118 : dom=0x7f19e002db00, (VM:
name=freenas1, uuid=07aadf11-2090-4690-9518-52766722c544),
15:51:31.566: 5796: debug : virUnrefDomain:276 : unref domain 0x7f19e002db00
freenas1 1
15:51:31.566: 5796: debug : virReleaseDomain:238 : release domain
0x7f19e002db00 freenas1 07aadf11-2090-4690-9518-52766722c544
15:51:31.566: 5796: debug : virReleaseDomain:246 : unref connection 0x6f6350 2
error: An error occurred, but the cause is unknown

#####

I f you have an idea of what the problem is...

Thank you,
jC

More information about the libvir-list mailing list