can't create VM in 12.04

Asked by Werner Kuballa on 2012-04-19

I can't create any VM in 12.04.

===> The system does support virtualization:
root@wkuballa185:~/tmp# kvm-ok
INFO: /dev/kvm exists
KVM acceleration can be used

===> I can start a VM manually just fine (the VM starts and boots from CD):
root@wkuballa185:~/tmp# kvm -m 1024 -cdrom /dev/cdrom

===> virsh reports these capabilities:
root@wkuballa185:~/tmp# virsh capabilities
<capabilities>
  <host>
    <uuid>44454c4c-3000-1030-8046-c8c04f304c31</uuid>
    <cpu>
      <arch>x86_64</arch>
      <model>Penryn</model>
      <vendor>Intel</vendor>
      <topology sockets='1' cores='2' threads='1'/>
      <feature name='xtpr'/>
      <feature name='tm2'/>
      <feature name='est'/>
      <feature name='vmx'/>
      <feature name='ds_cpl'/>
      <feature name='monitor'/>
      <feature name='pbe'/>
      <feature name='tm'/>
      <feature name='ht'/>
      <feature name='ss'/>
      <feature name='acpi'/>
      <feature name='ds'/>
      <feature name='vme'/>
    </cpu>
    <power_management>
      <suspend_mem/>
      <suspend_disk/>
      <suspend_hybrid/>
    </power_management>
    <migration_features>
      <live/>
      <uri_transports>
        <uri_transport>tcp</uri_transport>
      </uri_transports>
    </migration_features>
    <topology>
      <cells num='1'>
        <cell id='0'>
          <cpus num='2'>
            <cpu id='0'/>
            <cpu id='1'/>
          </cpus>
        </cell>
      </cells>
    </topology>
  </host>
</capabilities>

===> I am trying to use this xml file to create a new VM:
root@wkuballa185:~/tmp# cat vm-u1204.xml
<domain type='kvm'>
  <name>vm-u1204</name>
  <memory>1048576</memory>
  <vcpu>1</vcpu>
  <os>
    <type arch='x86_64' machine='pc-1.0'>hvm</type>
    <boot dev='cdrom'/>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <clock offset='utc'/>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <devices>
    <emulator>/usr/bin/kvm</emulator>
    <disk type='block' device='disk'>
      <driver name='qemu' type='raw'/>
      <source dev='/dev/mapper/SysVG-vm--u1204'/>
      <target dev='vda' bus='virtio'/>
    </disk>
    <disk type='file' device='cdrom'>
      <driver name='qemu' type='raw'/>
      <target dev='hdc' bus='ide'/>
      <source dev='/dev/cdrom'/>
      <readonly/>
    </disk>
    <interface type='network'>
      <mac address='52:54:00:54:31:17'/>
      <source network='default'/>
      <model type='virtio'/>
    </interface>
    <serial type='pty'>
      <target port='0'/>
    </serial>
    <console type='pty'>
      <target type='serial' port='0'/>
    </console>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes'/>
    <sound model='ac97'>
    </sound>
  </devices>
</domain>

===> trying to create the VM generates this output:
root@wkuballa185:~/tmp# virsh create vm-u1204.xml
error: Failed to create domain from vm-u1204.xml
error: unknown OS type hvm

===> with virsh debug enabled:
root@wkuballa185:~/tmp# export LIBVIRT_DEBUG=0
root@wkuballa185:~/tmp# virsh create vm-u1204.xml
2012-04-19 18:22:08.513+0000: 3561: info : libvirt version: 0.9.8
2012-04-19 18:22:08.513+0000: 3561: warning : virLogParseDefaultPriority:1170 : Ignoring invalid log level setting
libvir: Domain Config error : unknown OS type hvm
error: Failed to create domain from vm-u1204.xml
error: unknown OS type hvm

===> and with libvirt debug enabled:
root@wkuballa185:~/tmp# export LIBVIRT_DEBUG=1
root@wkuballa185:~2012-04-19 20:38:32.714+0000: 3630: info : libvirt version: 0.9.8
2012-04-19 20:38:32.714+0000: 3630: debug : virInitialize:414 : register drivers
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:775 : driver=0x7fd16cdbb8a0 name=Test
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:799 : registering Test as driver 0
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterNetworkDriver:592 : registering Test as network driver 0
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterInterfaceDriver:625 : registering Test as interface driver 0
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterStorageDriver:658 : registering Test as storage driver 0
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDeviceMonitor:691 : registering Test as device driver 0
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterSecretDriver:724 : registering Test as secret driver 0
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterNWFilterDriver:757 : registering Test as network filter driver 0
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:775 : driver=0x7fd16cdbcc80 name=Xen
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:799 : registering Xen as driver 1
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:775 : driver=0x7fd16cdbd4c0 name=OPENVZ
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:799 : registering OPENVZ as driver 2
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:775 : driver=0x7fd16cdbd980 name=VMWARE
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:799 : registering VMWARE as driver 3
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:775 : driver=0x7fd16cdbc100 name=remote
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDriver:799 : registering remote as driver 4
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterNetworkDriver:592 : registering remote as network driver 1
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterInterfaceDriver:625 : registering remote as interface driver 1
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterStorageDriver:658 : registering remote as storage driver 1
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterDeviceMonitor:691 : registering remote as device driver 1
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterSecretDriver:724 : registering remote as secret driver 1
2012-04-19 20:38:32.714+0000: 3630: debug : virRegisterNWFilterDriver:757 : registering remote as network filter driver 1
2012-04-19 20:38:32.714+0000: 3630: debug : virEventRegisterDefaultImpl:204 : registering default event implementation
2012-04-19 20:38:32.714+0000: 3630: debug : virEventPollAddHandle:116 : Used 0 handle slots, adding at least 10 more
2012-04-19 20:38:32.714+0000: 3630: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 0
2012-04-19 20:38:32.714+0000: 3630: debug : virEventPollAddHandle:141 : EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x7fd16ca40460 opaque=(nil) ff=(nil)
2012-04-19 20:38:32.714+0000: 3630: debug : virEventRegisterImpl:177 : addHandle=0x7fd16ca40ea0 updateHandle=0x7fd16ca40da0 removeHandle=0x7fd16ca40840 addTimeout=0x7fd16ca40980 updateTimeout=0x7fd16ca40b20 removeTimeout=0x7fd16ca40c30
2012-04-19 20:38:32.714+0000: 3630: debug : virConnectOpenAuth:1421 : name=qemu:///system, auth=0x7fd16cdbb820, flags=0
2012-04-19 20:38:32.714+0000: 3630: debug : virConnectOpenResolveURIAlias:1070 : Loading config file '/etc/libvirt/libvirt.conf'
2012-04-19 20:38:32.714+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.714+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 0
2012-04-19 20:38:32.714+0000: 3631: debug : virEventPollCleanupTimeouts:542 : Found 0 out of 0 timeout slots used, releasing 0
2012-04-19 20:38:32.714+0000: 3630: debug : do_open:1151 : name "qemu:///system" to URI components:
  scheme qemu
  opaque (null)
  authority (null)
  server (null)
  user (null)
  port 0
  path /system

2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1195 : trying driver 0 (Test) ...
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1201 : driver 0 Test returned DECLINED
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1195 : trying driver 1 (Xen) ...
2012-04-19 20:38:32.714+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1201 : driver 1 Xen returned DECLINED
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1195 : trying driver 2 (OPENVZ) ...
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 0 timers
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1201 : driver 2 OPENVZ returned DECLINED
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1195 : trying driver 3 (VMWARE) ...
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1201 : driver 3 VMWARE returned DECLINED
2012-04-19 20:38:32.715+0000: 3630: debug : do_open:1195 : trying driver 4 (remote) ...
2012-04-19 20:38:32.715+0000: 3630: debug : doRemoteOpen:534 : proceeding with name = qemu:///system
2012-04-19 20:38:32.715+0000: 3630: debug : doRemoteOpen:544 : Connecting with transport 1
2012-04-19 20:38:32.715+0000: 3630: debug : doRemoteOpen:591 : Proceeding with sockname /var/run/libvirt/libvirt-sock
2012-04-19 20:38:32.715+0000: 3630: debug : virNetSocketNew:119 : localAddr=0x7fff2909af40 remoteAddr=0x7fff2909afd0 fd=6 errfd=-1 pid=0
2012-04-19 20:38:32.715+0000: 3630: debug : virNetSocketNew:179 : RPC_SOCKET_NEW: sock=0x18f10e0 refs=1 fd=6 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
2012-04-19 20:38:32.715+0000: 3630: debug : virNetSocketRef:709 : RPC_SOCKET_REF: sock=0x18f10e0 refs=2
2012-04-19 20:38:32.715+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.715+0000: 3630: debug : virEventPollAddHandle:141 : EVENT_POLL_ADD_HANDLE: watch=2 fd=6 events=1 cb=0x7fd16cb0afb0 opaque=0x18f10e0 ff=0x7fd16cb0b5d0
2012-04-19 20:38:32.715+0000: 3630: debug : virKeepAliveNew:244 : client=0x7fd16cf7b010, interval=-1, count=0
2012-04-19 20:38:32.715+0000: 3630: debug : virEventPollAddTimeout:225 : Used 0 timeout slots, adding at least 10 more
2012-04-19 20:38:32.715+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.715+0000: 3630: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=-1 cb=0x7fd16cb079b0 opaque=0x18f0360 ff=0x7fd16cb07b60
2012-04-19 20:38:32.715+0000: 3630: debug : virKeepAliveNew:277 : RPC_KEEPALIVE_NEW: ka=0x18f0360 client=0x7fd16cf7b010 refs=2
2012-04-19 20:38:32.715+0000: 3630: debug : virNetClientNew:326 : RPC_CLIENT_NEW: client=0x7fd16cf7b010 refs=3 sock=0x18f10e0
2012-04-19 20:38:32.715+0000: 3630: debug : doRemoteOpen:676 : Trying authentication
2012-04-19 20:38:32.715+0000: 3630: debug : virNetMessageNew:48 : msg=0x7fd16cf3a010 tracked=0
2012-04-19 20:38:32.715+0000: 3630: debug : virNetMessageEncodePayload:351 : Encode length as 28
2012-04-19 20:38:32.715+0000: 3630: debug : virNetClientSendInternal:1685 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7fd16cf7b010 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0
2012-04-19 20:38:32.715+0000: 3630: debug : virNetClientIO:1543 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=(nil)
2012-04-19 20:38:32.715+0000: 3630: debug : virNetClientIO:1601 : We have the buck 0x18f3810 0x18f3810
2012-04-19 20:38:32.715+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2012-04-19 20:38:32.715+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.715+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.715+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.715+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.715+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.715+0000: 3630: debug : virNetMessageDecodeLength:149 : Got length, now need 36 total (32 more)
2012-04-19 20:38:32.715+0000: 3630: debug : virNetClientCallDispatch:936 : RPC_CLIENT_MSG_RX: client=0x7fd16cf7b010 len=36 prog=536903814 vers=1 proc=66 type=1 status=0 serial=0
2012-04-19 20:38:32.715+0000: 3630: debug : virKeepAliveCheckMessage:408 : ka=0x18f0360, client=0x7fd16cf7b010, msg=0x7fd16cf7b068
2012-04-19 20:38:32.716+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1256 : Giving up the buck 0x18f3810
2012-04-19 20:38:32.716+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1270 : No thread to pass the buck to
2012-04-19 20:38:32.716+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2012-04-19 20:38:32.716+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.716+0000: 3630: debug : virNetClientIO:1630 : All done with our call (nil) 0x18f3810 2
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2012-04-19 20:38:32.716+0000: 3630: debug : virNetMessageFree:75 : msg=0x7fd16cf3a010 nfds=0 cb=(nil)
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.716+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=1 d=0
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.716+0000: 3630: debug : virNetMessageNew:48 : msg=0x18f3eb0 tracked=0
2012-04-19 20:38:32.716+0000: 3630: debug : virNetMessageEncodePayload:351 : Encode length as 32
2012-04-19 20:38:32.716+0000: 3630: debug : virNetClientSendInternal:1685 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7fd16cf7b010 len=32 prog=536903814 vers=1 proc=60 type=0 status=0 serial=1
2012-04-19 20:38:32.716+0000: 3630: debug : virNetClientIO:1543 : Outgoing message prog=536903814 version=1 serial=1 proc=60 type=0 length=32 dispatch=(nil)
2012-04-19 20:38:32.716+0000: 3630: debug : virNetClientIO:1601 : We have the buck 0x18f3810 0x18f3810
2012-04-19 20:38:32.716+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2012-04-19 20:38:32.716+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 2
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.716+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.716+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.716+0000: 3630: debug : virNetMessageDecodeLength:149 : Got length, now need 32 total (28 more)
2012-04-19 20:38:32.716+0000: 3630: debug : virNetClientCallDispatch:936 : RPC_CLIENT_MSG_RX: client=0x7fd16cf7b010 len=32 prog=536903814 vers=1 proc=60 type=1 status=0 serial=1
2012-04-19 20:38:32.716+0000: 3630: debug : virKeepAliveCheckMessage:408 : ka=0x18f0360, client=0x7fd16cf7b010, msg=0x7fd16cf7b068
2012-04-19 20:38:32.717+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1256 : Giving up the buck 0x18f3810
2012-04-19 20:38:32.717+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1270 : No thread to pass the buck to
2012-04-19 20:38:32.717+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2012-04-19 20:38:32.717+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.717+0000: 3630: debug : virNetClientIO:1630 : All done with our call (nil) 0x18f3810 2
2012-04-19 20:38:32.717+0000: 3630: debug : virNetMessageFree:75 : msg=0x18f3eb0 nfds=0 cb=(nil)
2012-04-19 20:38:32.717+0000: 3630: debug : doRemoteOpen:702 : Trying to open URI qemu:///system
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.717+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.717+0000: 3630: debug : virNetMessageNew:48 : msg=0x18f3eb0 tracked=0
2012-04-19 20:38:32.717+0000: 3630: debug : virNetMessageEncodePayload:351 : Encode length as 56
2012-04-19 20:38:32.717+0000: 3630: debug : virNetClientSendInternal:1685 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7fd16cf7b010 len=56 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.717+0000: 3630: debug : virNetClientIO:1543 : Outgoing message prog=536903814 version=1 serial=2 proc=1 type=0 length=56 dispatch=(nil)
2012-04-19 20:38:32.717+0000: 3630: debug : virNetClientIO:1601 : We have the buck 0x18f3810 0x18f3810
2012-04-19 20:38:32.717+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=1 d=0
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2012-04-19 20:38:32.717+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 2
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.717+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 1
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 1 timers
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.717+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.718+0000: 3630: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
2012-04-19 20:38:32.718+0000: 3630: debug : virNetClientCallDispatch:936 : RPC_CLIENT_MSG_RX: client=0x7fd16cf7b010 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2
2012-04-19 20:38:32.718+0000: 3630: debug : virKeepAliveCheckMessage:408 : ka=0x18f0360, client=0x7fd16cf7b010, msg=0x7fd16cf7b068
2012-04-19 20:38:32.718+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1256 : Giving up the buck 0x18f3810
2012-04-19 20:38:32.718+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1270 : No thread to pass the buck to
2012-04-19 20:38:32.718+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2012-04-19 20:38:32.718+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.718+0000: 3630: debug : virNetClientIO:1630 : All done with our call (nil) 0x18f3810 2
2012-04-19 20:38:32.718+0000: 3630: debug : virNetMessageFree:75 : msg=0x18f3eb0 nfds=0 cb=(nil)
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.718+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.718+0000: 3630: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=2 frequency=-1 cb=0x7fd16cae42c0 opaque=0x18f36f0 ff=(nil)
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1201 : driver 4 remote returned SUCCESS
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1223 : network driver 0 Test returned DECLINED
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1223 : network driver 1 remote returned SUCCESS
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1238 : interface driver 0 Test returned DECLINED
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1238 : interface driver 1 remote returned SUCCESS
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1254 : storage driver 0 Test returned DECLINED
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1254 : storage driver 1 remote returned SUCCESS
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1270 : node driver 0 Test returned DECLINED
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1270 : node driver 1 remote returned SUCCESS
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1286 : secret driver 0 Test returned DECLINED
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1286 : secret driver 1 remote returned SUCCESS
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1302 : nwfilter driver 0 Test returned DECLINED
2012-04-19 20:38:32.718+0000: 3630: debug : do_open:1302 : nwfilter driver 1 remote returned SUCCESS
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=1 d=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 2 timers
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2012-04-19 20:38:32.718+0000: 3630: debug : virDomainCreateXML:1956 : conn=0x18f36f0, xmlDesc=<domain type='kvm'>
  <name>vm-u1204</name>
  <memory>1048576</memory>
  <vcpu>1</vcpu>
  <os>
    <type arch='x86_64' machine='pc-1.0'>hvm</type>
    <boot dev='cdrom'/>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <clock offset='utc'/>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <devices>
    <emulator>/usr/bin/kvm</emulator>
    <disk type='block' device='disk'>
      <driver name='qemu' type='raw'/>
      <source dev='/dev/mapper/SysVG-vm--u1204'/>
      <target dev='vda' bus='virtio'/>
    </disk>
    <disk type='file' device='cdrom'>
      <driver name='qemu' type='raw'/>
      <target dev='hdc' bus='ide'/>
      <source dev='/dev/cdrom'/>
      <readonly/>
    </disk>
    <interface type='network'>
      <mac address='52:54:00:54:31:17'/>
      <source network='default'/>
      <model type='virtio'/>
    </interface>
    <serial type='pty'>
      <target port='0'/>
    </serial>
    <console type='pty'>
      <target type='serial' port='0'/>
    </console>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes'/>
    <sound model='ac97'>
    </sound>
  </devices>
</domain>
, flags=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:474 : i=1 w=2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3630: debug : virNetMessageNew:48 : msg=0x18f5ec0 tracked=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=1 d=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 2 timers
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2012-04-19 20:38:32.718+0000: 3630: debug : virNetMessageEncodePayload:351 : Encode length as 1272
2012-04-19 20:38:32.718+0000: 3630: debug : virNetClientSendInternal:1685 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7fd16cf7b010 len=1272 prog=536903814 vers=1 proc=10 type=0 status=0 serial=3
2012-04-19 20:38:32.718+0000: 3630: debug : virNetClientIO:1543 : Outgoing message prog=536903814 version=1 serial=3 proc=10 type=0 length=1272 dispatch=(nil)
2012-04-19 20:38:32.718+0000: 3630: debug : virNetClientIO:1601 : We have the buck 0x18f3810 0x18f3810
2012-04-19 20:38:32.718+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2012-04-19 20:38:32.718+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 2 timers
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.718+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.719+0000: 3630: debug : virNetMessageDecodeLength:149 : Got length, now need 128 total (124 more)
2012-04-19 20:38:32.719+0000: 3630: debug : virNetClientCallDispatch:936 : RPC_CLIENT_MSG_RX: client=0x7fd16cf7b010 len=128 prog=536903814 vers=1 proc=10 type=1 status=1 serial=3
2012-04-19 20:38:32.719+0000: 3630: debug : virKeepAliveCheckMessage:408 : ka=0x18f0360, client=0x7fd16cf7b010, msg=0x7fd16cf7b068
2012-04-19 20:38:32.719+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1256 : Giving up the buck 0x18f3810
2012-04-19 20:38:32.719+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1270 : No thread to pass the buck to
2012-04-19 20:38:32.719+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2012-04-19 20:38:32.719+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.719+0000: 3630: debug : virNetClientIO:1630 : All done with our call (nil) 0x18f3810 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.719+0000: 3630: debug : virNetMessageFree:75 : msg=0x18f5ec0 nfds=0 cb=(nil)
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
libvir: Domain Config error : unknown OS type hvm
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
error: 2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=1 d=0
Failed to create domain from vm-u1204.xml
error: unknown OS type hvm
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=2 imeout=-1
2012-04-19 20:38:32.719+0000: 3630: debug : virConnectClose:1462 : conn=0x18f36f0
2012-04-19 20:38:32.719+0000: 3630: debug : virUnrefConnect:145 : unref connection 0x18f36f0 1
2012-04-19 20:38:32.719+0000: 3630: debug : virReleaseConnect:94 : release connection 0x18f36f0
2012-04-19 20:38:32.719+0000: 3630: debug : virNetMessageNew:48 : msg=0x18f3eb0 tracked=0
2012-04-19 20:38:32.719+0000: 3630: debug : virNetMessageEncodePayload:351 : Encode length as 28
2012-04-19 20:38:32.719+0000: 3630: debug : virNetClientSendInternal:1685 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7fd16cf7b010 len=28 prog=536903814 vers=1 proc=2 type=0 status=0 serial=4
2012-04-19 20:38:32.719+0000: 3630: debug : virNetClientIO:1543 : Outgoing message prog=536903814 version=1 serial=4 proc=2 type=0 length=28 dispatch=(nil)
2012-04-19 20:38:32.719+0000: 3630: debug : virNetClientIO:1601 : We have the buck 0x18f3810 0x18f3810
2012-04-19 20:38:32.719+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
2012-04-19 20:38:32.719+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventRunDefaultImpl:244 : running default event implementation
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=4 e=1 d=0
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=6 e=0 d=0
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 2 timers
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
2012-04-19 20:38:32.719+0000: 3631: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=1 imeout=-1
2012-04-19 20:38:32.720+0000: 3630: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
2012-04-19 20:38:32.720+0000: 3630: debug : virNetClientCallDispatch:936 : RPC_CLIENT_MSG_RX: client=0x7fd16cf7b010 len=28 prog=536903814 vers=1 proc=2 type=1 status=0 serial=4
2012-04-19 20:38:32.720+0000: 3630: debug : virKeepAliveCheckMessage:408 : ka=0x18f0360, client=0x7fd16cf7b010, msg=0x7fd16cf7b068
2012-04-19 20:38:32.720+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1256 : Giving up the buck 0x18f3810
2012-04-19 20:38:32.720+0000: 3630: debug : virNetClientIOEventLoopPassTheBuck:1270 : No thread to pass the buck to
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.720+0000: 3630: debug : virNetClientIO:1630 : All done with our call (nil) 0x18f3810 2
2012-04-19 20:38:32.720+0000: 3630: debug : virNetMessageFree:75 : msg=0x18f3eb0 nfds=0 cb=(nil)
2012-04-19 20:38:32.720+0000: 3630: debug : virNetClientCloseLocked:483 : client=0x7fd16cf7b010, sock=0x18f10e0
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=2
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollRemoveHandle:193 : mark delete 1 6
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.720+0000: 3630: debug : virNetSocketFree:722 : RPC_SOCKET_FREE: sock=0x18f10e0 refs=2
2012-04-19 20:38:32.720+0000: 3630: debug : virKeepAliveStop:382 : RPC_KEEPALIVE_STOP: ka=0x18f0360 client=0x7fd16cf7b010
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=1
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.720+0000: 3630: debug : virKeepAliveFree:304 : RPC_KEEPALIVE_FREE: ka=0x18f0360 client=0x7fd16cf7b010 refs=2
2012-04-19 20:38:32.720+0000: 3630: debug : virNetClientFree:448 : RPC_CLIENT_FREE: client=0x7fd16cf7b010 refs=3
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=2
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollInterruptLocked:706 : Interrupting
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=3 frequency=0 cb=0x40b4b0 opaque=(nil) ff=(nil)
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollDispatchTimeouts:415 : Dispatch 3
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollDispatchTimeouts:438 : EVENT_POLL_DISPATCH_TIMEOUT: timer=3
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollDispatchHandles:460 : Dispatch 1
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollDispatchHandles:474 : i=0 w=1
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollCleanupTimeouts:519 : EVENT_POLL_PURGE_TIMEOUT: timer=1
2012-04-19 20:38:32.720+0000: 3631: debug : virKeepAliveFree:304 : RPC_KEEPALIVE_FREE: ka=0x18f0360 client=0x7fd16cf7b010 refs=1
2012-04-19 20:38:32.720+0000: 3631: debug : virNetClientFree:448 : RPC_CLIENT_FREE: client=0x7fd16cf7b010 refs=2
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollCleanupTimeouts:519 : EVENT_POLL_PURGE_TIMEOUT: timer=2
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollCleanupHandles:554 : Cleanup 2
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollCleanupHandles:567 : EVENT_POLL_PURGE_HANDLE: watch=2
2012-04-19 20:38:32.720+0000: 3631: debug : virNetClientFree:448 : RPC_CLIENT_FREE: client=0x7fd16cf7b010 refs=1
2012-04-19 20:38:32.720+0000: 3631: debug : virNetSocketFree:722 : RPC_SOCKET_FREE: sock=0x18f10e0 refs=1
2012-04-19 20:38:32.720+0000: 3631: debug : virNetSocketFree:730 : sock=0x18f10e0 fd=6
2012-04-19 20:38:32.720+0000: 3631: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=2
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=3
2012-04-19 20:38:32.720+0000: 3630: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 1656493824

===> anybody got an idea what I am doing wrong?

Regards,
Werner

Question information

Language:
English Edit question
Status:
Answered
For:
Ubuntu kvm Edit question
Assignee:
No assignee Edit question
Last query:
2012-04-19
Last reply:
2012-04-20

Have you reported a bug. Precise is not ready and not stable.

Can you help with this problem?

Provide an answer of your own, or ask Werner Kuballa for more information if necessary.

To post a message you must log in.