Attachment 706535 Details for Bug 919004 – crashed libvirtd log

crashed libvirtd log

libvirtd.log (text/plain), 78.43 KB, created by EricLee on 2013-03-07 11:44:14 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: EricLee

Created: 2013-03-07 11:44:14 UTC

Size: 78.43 KB

patch

obsolete

>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectNew:201 : OBJECT_NEW: obj=0xa10c40 classname=virNetSocket
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectNew:201 : OBJECT_NEW: obj=0xa10a80 classname=virNetServerClient
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10c40
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10c40
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectNew:201 : OBJECT_NEW: obj=0xa11530 classname=virKeepAlive
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10c40
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.229+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:35:36.229+0000: 23448: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:35:36.229+0000: 23448: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:35:36.230+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.230+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:35:36.230+0000: 23449: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:35:36.230+0000: 23449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:35:36.230+0000: 23449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:35:36.231+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.231+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:35:36.231+0000: 23450: debug : virConnectOpen:1365 : name=
>2013-03-07 08:35:36.231+0000: 23450: debug : virObjectNew:201 : OBJECT_NEW: obj=0x7f99bc000ae0 classname=virConnect
>2013-03-07 08:35:36.231+0000: 23450: debug : virConnectGetConfigFile:980 : Loading config file '/etc/libvirt/libvirt.conf'
>2013-03-07 08:35:36.231+0000: 23450: debug : virConfReadFile:767 : filename=/etc/libvirt/libvirt.conf
>2013-03-07 08:35:36.231+0000: 23450: debug : virFileClose:72 : Closed fd 20
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1158 : no name, allowing driver auto-select
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1200 : trying driver 0 (Test) ...
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1206 : driver 0 Test returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1200 : trying driver 1 (ESX) ...
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1206 : driver 1 ESX returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1200 : trying driver 2 (remote) ...
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1206 : driver 2 remote returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1200 : trying driver 3 (QEMU) ...
>2013-03-07 08:35:36.231+0000: 23450: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c0007c60
>2013-03-07 08:35:36.231+0000: 23450: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99c0007c60
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1206 : driver 3 QEMU returned SUCCESS
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1230 : network driver 0 Test returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1230 : network driver 1 ESX returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1230 : network driver 2 remote returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1230 : network driver 3 Network returned SUCCESS
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1246 : interface driver 0 Test returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1246 : interface driver 1 ESX returned DECLINED
>2013-03-07 08:35:36.231+0000: 23450: debug : do_open:1246 : interface driver 2 remote returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1246 : interface driver 3 netcf returned SUCCESS
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1263 : storage driver 0 Test returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1263 : storage driver 1 ESX returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1263 : storage driver 2 remote returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1263 : storage driver 3 storage returned SUCCESS
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1280 : node driver 0 Test returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1280 : node driver 1 ESX returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1280 : node driver 2 remote returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1280 : node driver 3 udevDeviceMonitor returned SUCCESS
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1297 : secret driver 0 Test returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1297 : secret driver 1 ESX returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1297 : secret driver 2 remote returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1297 : secret driver 3 secret returned SUCCESS
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1314 : nwfilter driver 0 Test returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1314 : nwfilter driver 1 ESX returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1314 : nwfilter driver 2 remote returned DECLINED
>2013-03-07 08:35:36.238+0000: 23450: debug : do_open:1314 : nwfilter driver 3 nwfilter returned SUCCESS
>2013-03-07 08:35:36.238+0000: 23450: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:35:36.238+0000: 23450: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:35:36.239+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.239+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:35:36.239+0000: 23451: debug : virConnectGetURI:1734 : conn=0x7f99bc000ae0
>2013-03-07 08:35:36.239+0000: 23451: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:35:36.239+0000: 23451: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:35:36.240+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.240+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:35:36.240+0000: 23452: debug : virDomainLookupByName:2151 : conn=0x7f99bc000ae0, name=guest
>2013-03-07 08:35:36.240+0000: 23452: debug : virObjectNew:201 : OBJECT_NEW: obj=0x7f99b4000ae0 classname=virDomain
>2013-03-07 08:35:36.240+0000: 23452: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99bc000ae0
>2013-03-07 08:35:36.240+0000: 23452: debug : virDomainFree:2315 : dom=0x7f99b4000ae0, (VM: name=guest, uuid=ecd5836e-f152-f4b8-3cf9-9997db95d7d7)
>2013-03-07 08:35:36.240+0000: 23452: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99b4000ae0
>2013-03-07 08:35:36.240+0000: 23452: debug : virObjectUnref:260 : OBJECT_DISPOSE: obj=0x7f99b4000ae0
>2013-03-07 08:35:36.240+0000: 23452: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99bc000ae0
>2013-03-07 08:35:36.240+0000: 23452: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:35:36.240+0000: 23452: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:35:36.240+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:35:36.240+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectNew:201 : OBJECT_NEW: obj=0x7f99c03cec50 classname=virDomain
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99bc000ae0
>2013-03-07 08:35:36.241+0000: 23448: debug : virDomainGetXMLDesc:4373 : dom=0x7f99c03cec50, (VM: name=guest, uuid=ecd5836e-f152-f4b8-3cf9-9997db95d7d7), flags=3
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c021ce80
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99c021ce80
>2013-03-07 08:35:36.241+0000: 23448: debug : virDomainFree:2315 : dom=0x7f99c03cec50, (VM: name=guest, uuid=ecd5836e-f152-f4b8-3cf9-9997db95d7d7)
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99c03cec50
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectUnref:260 : OBJECT_DISPOSE: obj=0x7f99c03cec50
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99bc000ae0
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:35:36.241+0000: 23448: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:35:41.245+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:35:41.245+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:35:46.252+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:35:46.252+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:35:51.258+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:35:51.258+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:35:56.263+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:35:56.263+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:01.269+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:36:01.269+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:06.275+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:36:06.275+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:11.281+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:36:11.281+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:16.287+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:36:16.287+0000: 23447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:17.589+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:36:17.589+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectNew:201 : OBJECT_NEW: obj=0x7f99b8000b70 classname=virDomain
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99bc000ae0
>2013-03-07 08:36:17.589+0000: 23449: debug : virDomainGetXMLDesc:4373 : dom=0x7f99b8000b70, (VM: name=guest, uuid=ecd5836e-f152-f4b8-3cf9-9997db95d7d7), flags=3
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c021ce80
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99c021ce80
>2013-03-07 08:36:17.589+0000: 23449: debug : virDomainFree:2315 : dom=0x7f99b8000b70, (VM: name=guest, uuid=ecd5836e-f152-f4b8-3cf9-9997db95d7d7)
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99b8000b70
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectUnref:260 : OBJECT_DISPOSE: obj=0x7f99b8000b70
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99bc000ae0
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:36:17.589+0000: 23449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:36:17.590+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:36:17.590+0000: 23447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:36:17.590+0000: 23450: debug : virDomainDefineXML:8088 : conn=0x7f99bc000ae0, xml=<domain type='kvm'>
>  <name>guest</name>
>  <uuid>ecd5836e-f152-f4b8-3cf9-9997db95d7d7</uuid>
>  <memory unit='KiB'>1048576</memory>
>  <currentMemory unit='KiB'>1048576</currentMemory>
>  <vcpu placement='static'>1</vcpu>
>  <os>
>    <type arch='x86_64' machine='pc-1.3'>hvm</type>
>    <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/libexec/qemu-kvm</emulator>
>    <disk type='file' device='disk'>
>      <driver name='qemu' type='raw'/>
>      <source file='/var/lib/libvirt/images/guest.img'/>
>      <target dev='hda' bus='ide'/>
>      <address type='drive' controller='0' bus='0' target='0' unit='0'/>
>    </disk>
>    <controller type='usb' index='0'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
>    </controller>
>    <controller type='ide' index='0'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x1'/>
>    </controller>
>    <controller type='virtio-serial' index='0'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
>    </controller>
>    <interface type='network'>
>      <mac address='52:54:00:37:f1:84'/>
>      <source network='default'/>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
>    </interface>
>    <serial type='pty'>
>      <target port='0'/>
>    </serial>
>    <console type='pty'>
>      <target type='serial' port='0'/>
>    </console>
>    <channel type='spicevmc'>
>      <target type='virtio' name='com.redhat.spice.0'/>
>      <address type='virtio-serial' controller='0' bus='0' port='1'/>
>    </channel>
>    <input type='mouse' bus='ps2'/>
>    <graphics type='spice' autoport='yes'/>
>    <sound model='ich6'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
>    </sound>
>    <video>
>      <model type='qxl' ram='65536' vram='65536' heads='1'/>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
>    </video>
>    <memballoon model='virtio'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>
>    </memballoon>
>  <rng model='virtio'>
>    <backend model='random'/>
>  </rng>
>  </devices>
></domain>
>
>2013-03-07 08:36:17.590+0000: 23450: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c0007c60
>2013-03-07 08:36:17.590+0000: 23450: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c021ce80
>Caught Segmentation violation dumping internal log buffer:
>
>
>    ====== start of log =====
>
>rEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:01.270+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:01.270+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645366270
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645366270 now=1362645361270
>2013-03-07 08:36:01.270+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645366270 due in 5000 ms
>2013-03-07 08:36:01.270+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:06.275+000023447: debug : virEventPollRunOnce:640 : Poll got 0 event(s)
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchTimeouts:448 : EVENT_POLL_DISPATCH_TIMEOUT: timer=2
>2013-03-07 08:36:06.275+000023447: debug : virKeepAliveTimerInternal:134 : RPC_KEEPALIVE_TIMEOUT: ka=0xa11530 client=0xa10a80 countToDeath=5 idle=5
>2013-03-07 08:36:06.275+000023447: debug : virNetMessageNew:45 : msg=0xa0ff80 tracked=0
>2013-03-07 08:36:06.275+000023447: debug : virNetMessageEncodePayloadEmpty:454 : Encode length as 28
>2013-03-07 08:36:06.275+000023447: debug : virKeepAliveMessage:102 : Sending keepalive request to client 0xa10a80
>2013-03-07 08:36:06.275+000023447: debug : virKeepAliveMessage:105 : RPC_KEEPALIVE_SEND: ka=0xa11530 client=0xa10a80 prog=1801807216 vers=1 proc=1
>2013-03-07 08:36:06.275+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:06.275+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645371275
>2013-03-07 08:36:06.275+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:06.275+000023447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientSendMessageLocked:1287 : msg=0xa0ff80 proc=1 len=28 offset=0
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientSendMessageLocked:1295 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0xa10a80 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=0xa0ff80
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-03-07 08:36:06.275+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=3
>2013-03-07 08:36:06.275+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:06.275+000023447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:06.275+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=5 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645371275
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645371275 now=1362645366275
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645371275 due in 5000 ms
>2013-03-07 08:36:06.275+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:06.275+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=2
>2013-03-07 08:36:06.275+000023447: debug : virNetMessageFree:73 : msg=0xa0ff80 nfds=0 cb=(nil)
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:06.275+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:06.275+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:06.275+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645371275
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645371275 now=1362645366275
>2013-03-07 08:36:06.275+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645371275 due in 5000 ms
>2013-03-07 08:36:06.275+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:06.275+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:06.275+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1
>2013-03-07 08:36:06.275+000023447: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:06.275+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:06.275+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:06.275+000023447: debug : virNetServerClientDispatchRead:1036 : RPC_SERVER_CLIENT_MSG_RX: client=0xa10a80 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2013-03-07 08:36:06.275+000023447: debug : virKeepAliveCheckMessage:372 : ka=0xa11530, client=0xa10a80, msg=0xa0fcd0
>2013-03-07 08:36:06.275+000023447: debug : virKeepAliveCheckMessage:389 : RPC_KEEPALIVE_RECEIVED: ka=0xa11530 client=0xa10a80 prog=1801807216 vers=1 proc=2
>2013-03-07 08:36:06.275+000023447: debug : virKeepAliveCheckMessage:398 : Got keepalive response from client 0xa10a80
>2013-03-07 08:36:06.276+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:06.276+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645371276
>2013-03-07 08:36:06.276+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:06.276+000023447: debug : virNetMessageFree:73 : msg=0xa0fcd0 nfds=0 cb=(nil)
>2013-03-07 08:36:06.276+000023447: debug : virNetMessageNew:45 : msg=0xa0fcd0 tracked=1
>2013-03-07 08:36:06.276+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:06.276+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:06.276+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:06.276+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:06.276+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645371276
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645371276 now=1362645366276
>2013-03-07 08:36:06.276+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645371276 due in 5000 ms
>2013-03-07 08:36:06.276+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:11.281+000023447: debug : virEventPollRunOnce:640 : Poll got 0 event(s)
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchTimeouts:448 : EVENT_POLL_DISPATCH_TIMEOUT: timer=2
>2013-03-07 08:36:11.281+000023447: debug : virKeepAliveTimerInternal:134 : RPC_KEEPALIVE_TIMEOUT: ka=0xa11530 client=0xa10a80 countToDeath=5 idle=5
>2013-03-07 08:36:11.281+000023447: debug : virNetMessageNew:45 : msg=0xa10610 tracked=0
>2013-03-07 08:36:11.281+000023447: debug : virNetMessageEncodePayloadEmpty:454 : Encode length as 28
>2013-03-07 08:36:11.281+000023447: debug : virKeepAliveMessage:102 : Sending keepalive request to client 0xa10a80
>2013-03-07 08:36:11.281+000023447: debug : virKeepAliveMessage:105 : RPC_KEEPALIVE_SEND: ka=0xa11530 client=0xa10a80 prog=1801807216 vers=1 proc=1
>2013-03-07 08:36:11.281+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:11.281+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645376281
>2013-03-07 08:36:11.281+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:11.281+000023447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:36:11.281+000023447: debug : virNetServerClientSendMessageLocked:1287 : msg=0xa10610 proc=1 len=28 offset=0
>2013-03-07 08:36:11.281+000023447: debug : virNetServerClientSendMessageLocked:1295 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0xa10a80 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2013-03-07 08:36:11.281+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=0xa10610
>2013-03-07 08:36:11.281+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-03-07 08:36:11.281+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=3
>2013-03-07 08:36:11.281+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:11.281+000023447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:11.281+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=5 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645376281
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645376281 now=1362645371281
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645376281 due in 5000 ms
>2013-03-07 08:36:11.281+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:11.281+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:11.281+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=2
>2013-03-07 08:36:11.281+000023447: debug : virNetMessageFree:73 : msg=0xa10610 nfds=0 cb=(nil)
>2013-03-07 08:36:11.281+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:11.281+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:11.281+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:11.281+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:11.281+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645376281
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645376281 now=1362645371281
>2013-03-07 08:36:11.281+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645376281 due in 5000 ms
>2013-03-07 08:36:11.282+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:11.282+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:11.282+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1
>2013-03-07 08:36:11.282+000023447: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2013-03-07 08:36:11.282+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:11.282+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:11.282+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:11.282+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:11.282+000023447: debug : virNetServerClientDispatchRead:1036 : RPC_SERVER_CLIENT_MSG_RX: client=0xa10a80 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2013-03-07 08:36:11.282+000023447: debug : virKeepAliveCheckMessage:372 : ka=0xa11530, client=0xa10a80, msg=0xa0fcd0
>2013-03-07 08:36:11.282+000023447: debug : virKeepAliveCheckMessage:389 : RPC_KEEPALIVE_RECEIVED: ka=0xa11530 client=0xa10a80 prog=1801807216 vers=1 proc=2
>2013-03-07 08:36:11.282+000023447: debug : virKeepAliveCheckMessage:398 : Got keepalive response from client 0xa10a80
>2013-03-07 08:36:11.282+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:11.282+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645376282
>2013-03-07 08:36:11.282+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:11.282+000023447: debug : virNetMessageFree:73 : msg=0xa0fcd0 nfds=0 cb=(nil)
>2013-03-07 08:36:11.282+000023447: debug : virNetMessageNew:45 : msg=0xa0fcd0 tracked=1
>2013-03-07 08:36:11.282+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:11.282+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:11.282+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:11.282+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:11.282+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645376282
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645376282 now=1362645371282
>2013-03-07 08:36:11.282+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645376282 due in 5000 ms
>2013-03-07 08:36:11.282+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:16.287+000023447: debug : virEventPollRunOnce:640 : Poll got 0 event(s)
>2013-03-07 08:36:16.287+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:16.287+000023447: debug : virEventPollDispatchTimeouts:448 : EVENT_POLL_DISPATCH_TIMEOUT: timer=2
>2013-03-07 08:36:16.287+000023447: debug : virKeepAliveTimerInternal:134 : RPC_KEEPALIVE_TIMEOUT: ka=0xa11530 client=0xa10a80 countToDeath=5 idle=5
>2013-03-07 08:36:16.287+000023447: debug : virNetMessageNew:45 : msg=0xa10280 tracked=0
>2013-03-07 08:36:16.287+000023447: debug : virNetMessageEncodePayloadEmpty:454 : Encode length as 28
>2013-03-07 08:36:16.287+000023447: debug : virKeepAliveMessage:102 : Sending keepalive request to client 0xa10a80
>2013-03-07 08:36:16.287+000023447: debug : virKeepAliveMessage:105 : RPC_KEEPALIVE_SEND: ka=0xa11530 client=0xa10a80 prog=1801807216 vers=1 proc=1
>2013-03-07 08:36:16.287+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:16.287+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645381287
>2013-03-07 08:36:16.287+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:16.287+000023447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa11530
>2013-03-07 08:36:16.287+000023447: debug : virNetServerClientSendMessageLocked:1287 : msg=0xa10280 proc=1 len=28 offset=0
>2013-03-07 08:36:16.287+000023447: debug : virNetServerClientSendMessageLocked:1295 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0xa10a80 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2013-03-07 08:36:16.287+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=0xa10280
>2013-03-07 08:36:16.287+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-03-07 08:36:16.287+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=3
>2013-03-07 08:36:16.287+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:16.287+000023447: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa11530
>2013-03-07 08:36:16.287+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:16.287+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:16.287+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:16.287+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:16.287+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:16.287+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=5 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645381287
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645381287 now=1362645376288
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645381287 due in 4999 ms
>2013-03-07 08:36:16.288+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=4999
>2013-03-07 08:36:16.288+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=2
>2013-03-07 08:36:16.288+000023447: debug : virNetMessageFree:73 : msg=0xa10280 nfds=0 cb=(nil)
>2013-03-07 08:36:16.288+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:16.288+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:16.288+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645381287
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645381287 now=1362645376288
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645381287 due in 4999 ms
>2013-03-07 08:36:16.288+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=4999
>2013-03-07 08:36:16.288+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:16.288+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1
>2013-03-07 08:36:16.288+000023447: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2013-03-07 08:36:16.288+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:16.288+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:16.288+000023447: debug : virNetServerClientDispatchRead:1036 : RPC_SERVER_CLIENT_MSG_RX: client=0xa10a80 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2013-03-07 08:36:16.288+000023447: debug : virKeepAliveCheckMessage:372 : ka=0xa11530, client=0xa10a80, msg=0xa0fcd0
>2013-03-07 08:36:16.288+000023447: debug : virKeepAliveCheckMessage:389 : RPC_KEEPALIVE_RECEIVED: ka=0xa11530 client=0xa10a80 prog=1801807216 vers=1 proc=2
>2013-03-07 08:36:16.288+000023447: debug : virKeepAliveCheckMessage:398 : Got keepalive response from client 0xa10a80
>2013-03-07 08:36:16.288+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:16.288+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645381288
>2013-03-07 08:36:16.288+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:16.288+000023447: debug : virNetMessageFree:73 : msg=0xa0fcd0 nfds=0 cb=(nil)
>2013-03-07 08:36:16.288+000023447: debug : virNetMessageNew:45 : msg=0xa0fcd0 tracked=1
>2013-03-07 08:36:16.288+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:16.288+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:16.288+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:16.288+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645381288
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645381288 now=1362645376288
>2013-03-07 08:36:16.288+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645381288 due in 5000 ms
>2013-03-07 08:36:16.288+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:17.589+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1
>2013-03-07 08:36:17.589+000023447: debug : virNetMessageDecodeLength:152 : Got length, now need 64 total (60 more)
>2013-03-07 08:36:17.589+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0fcd0 tx=(nil)
>2013-03-07 08:36:17.589+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:17.589+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:17.589+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:17.589+000023447: debug : virNetServerClientDispatchRead:1036 : RPC_SERVER_CLIENT_MSG_RX: client=0xa10a80 len=64 prog=536903814 vers=1 proc=14 type=0 status=0 serial=6
>2013-03-07 08:36:17.589+000023447: debug : virKeepAliveCheckMessage:372 : ka=0xa11530, client=0xa10a80, msg=0xa0fcd0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:17.589+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645382589
>2013-03-07 08:36:17.589+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:17.589+000023447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:36:17.589+000023447: debug : virNetServerDispatchNewMessage:210 : server=0x9f2a00 client=0xa10a80 message=0xa0fcd0
>2013-03-07 08:36:17.589+000023447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:36:17.589+000023447: debug : virNetMessageNew:45 : msg=0xa11940 tracked=1
>2013-03-07 08:36:17.589+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa11940 tx=(nil)
>2013-03-07 08:36:17.589+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:17.589+000023449: debug : virNetServerHandleJob:181 : server=0x9f2a00 client=0xa10a80 message=0xa0fcd0 prog=0xa0b970
>2013-03-07 08:36:17.589+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:17.589+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:17.589+000023449: debug : virNetServerProgramDispatch:285 : prog=536903814 ver=1 type=0 status=0 serial=6 proc=14
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.589+000023449: debug : remoteDispatchDomainGetXMLDescHelper:2636 : server=0x9f2a00 client=0xa10a80 msg=0xa0fcd0 rerr=0x7f99cdb12c20 args=0x7f99b8000bb0 ret=0x7f99b8000c50
>2013-03-07 08:36:17.589+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.589+000023449: debug : virObjectNew:201 : OBJECT_NEW: obj=0x7f99b8000b70 classname=virDomain
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.589+000023449: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99bc000ae0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:17.589+000023449: debug : virDomainGetXMLDesc:4373 : dom=0x7f99b8000b70, (VM: name=guest, uuid=ecd5836e-f152-f4b8-3cf9-9997db95d7d7), flags=3
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:17.589+000023449: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c021ce80
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645382589
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645382589 now=1362645377589
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645382589 due in 5000 ms
>2013-03-07 08:36:17.589+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:17.589+000023449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99c021ce80
>2013-03-07 08:36:17.589+000023449: debug : virDomainFree:2315 : dom=0x7f99b8000b70, (VM: name=guest, uuid=ecd5836e-f152-f4b8-3cf9-9997db95d7d7)
>2013-03-07 08:36:17.589+000023449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99b8000b70
>2013-03-07 08:36:17.589+000023449: debug : virObjectUnref:260 : OBJECT_DISPOSE: obj=0x7f99b8000b70
>2013-03-07 08:36:17.589+000023449: debug : virDomainDispose:226 : release domain 0x7f99b8000b70 guest ecd5836e-f152-f4b8-3cf9-9997db95d7d7
>2013-03-07 08:36:17.589+000023449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0x7f99bc000ae0
>2013-03-07 08:36:17.589+000023449: debug : virNetMessageEncodePayload:364 : Encode length as 2304
>2013-03-07 08:36:17.589+000023449: debug : virNetServerClientSendMessageLocked:1287 : msg=0xa0fcd0 proc=14 len=2304 offset=0
>2013-03-07 08:36:17.589+000023449: debug : virNetServerClientSendMessageLocked:1295 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0xa10a80 len=2304 prog=536903814 vers=1 proc=14 type=1 status=0 serial=6
>2013-03-07 08:36:17.589+000023449: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa11940 tx=0xa0fcd0
>2013-03-07 08:36:17.589+000023449: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-03-07 08:36:17.589+000023449: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=3
>2013-03-07 08:36:17.589+000023449: debug : virEventPollInterruptLocked:716 : Interrupting
>2013-03-07 08:36:17.589+000023449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa0b970
>2013-03-07 08:36:17.589+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:17.589+000023449: debug : virObjectUnref:258 : OBJECT_UNREF: obj=0xa10a80
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.589+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=5 d=0
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645382589
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645382589 now=1362645377589
>2013-03-07 08:36:17.589+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645382589 due in 5000 ms
>2013-03-07 08:36:17.589+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>2013-03-07 08:36:17.589+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:17.589+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=2
>2013-03-07 08:36:17.590+000023447: debug : virNetMessageFree:73 : msg=0xa0fcd0 nfds=0 cb=(nil)
>2013-03-07 08:36:17.590+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa11940 tx=(nil)
>2013-03-07 08:36:17.590+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:17.590+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:17.590+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.590+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645382589
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645382589 now=1362645377590
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645382589 due in 4999 ms
>2013-03-07 08:36:17.590+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=4999
>2013-03-07 08:36:17.590+000023447: debug : virEventPollRunOnce:640 : Poll got 1 event(s)
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchTimeouts:425 : Dispatch 2
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:470 : Dispatch 9
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=0 w=1
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=1 w=2
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=2 w=3
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=3 w=4
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=4 w=5
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=5 w=6
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=7 w=8
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=8 w=9
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:484 : i=9 w=11
>2013-03-07 08:36:17.590+000023447: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1
>2013-03-07 08:36:17.590+000023447: debug : virNetMessageDecodeLength:152 : Got length, now need 2368 total (2364 more)
>2013-03-07 08:36:17.590+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa11940 tx=(nil)
>2013-03-07 08:36:17.590+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:17.590+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:17.590+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:17.590+000023447: debug : virNetServerClientDispatchRead:1036 : RPC_SERVER_CLIENT_MSG_RX: client=0xa10a80 len=2368 prog=536903814 vers=1 proc=11 type=0 status=0 serial=7
>2013-03-07 08:36:17.590+000023447: debug : virKeepAliveCheckMessage:372 : ka=0xa11530, client=0xa10a80, msg=0xa11940
>2013-03-07 08:36:17.590+000023447: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
>2013-03-07 08:36:17.590+000023447: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1362645382590
>2013-03-07 08:36:17.590+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:17.590+000023447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa10a80
>2013-03-07 08:36:17.590+000023447: debug : virNetServerDispatchNewMessage:210 : server=0x9f2a00 client=0xa10a80 message=0xa11940
>2013-03-07 08:36:17.590+000023447: debug : virObjectRef:295 : OBJECT_REF: obj=0xa0b970
>2013-03-07 08:36:17.590+000023447: debug : virNetMessageNew:45 : msg=0xa0f7e0 tracked=1
>2013-03-07 08:36:17.590+000023447: debug : virNetServerClientCalculateHandleMode:148 : tls=(nil) hs=-1, rx=0xa0f7e0 tx=(nil)
>2013-03-07 08:36:17.590+000023450: debug : virNetServerHandleJob:181 : server=0x9f2a00 client=0xa10a80 message=0xa11940 prog=0xa0b970
>2013-03-07 08:36:17.590+000023447: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-03-07 08:36:17.590+000023450: debug : virNetServerProgramDispatch:285 : prog=536903814 ver=1 type=0 status=0 serial=7 proc=11
>2013-03-07 08:36:17.590+000023447: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=1
>2013-03-07 08:36:17.590+000023447: debug : virEventPollInterruptLocked:712 : Skip interrupt, 1 -726505344
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.590+000023447: debug : virEventRunDefaultImpl:270 : running default event implementation
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupTimeouts:516 : Cleanup 2
>2013-03-07 08:36:17.590+000023450: debug : remoteDispatchDomainDefineXMLHelper:1203 : server=0x9f2a00 client=0xa10a80 msg=0xa11940 rerr=0x7f99cd311c20 args=0x7f99bc0be6d0 ret=0x7f99bc0be730
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCleanupHandles:564 : Cleanup 10
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=6 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=8 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-03-07 08:36:17.590+000023450: debug : virDomainDefineXML:8088 : conn=0x7f99bc000ae0, xml=<domain type='kvm'>
>  <name>guest</name>
>  <uuid>ecd5836e-f152-f4b8-3cf9-9997db95d7d7</uuid>
>  <memory unit='KiB'>1048576</memory>
>  <currentMemory unit='KiB'>1048576</currentMemory>
>  <vcpu placement='static'>1</vcpu>
>  <os>
>    <type arch='x86_64' machine='pc-1.3'>hvm</type>
>    <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/libexec/qemu-kvm</emulator>
>    <disk type='file' device='disk'>
>      <driver name='qemu' type='raw'/>
>      <source file='/var/lib/libvirt/images/guest.img'/>
>      <target dev='hda' bus='ide'/>
>      <address type='drive' controller='0' bus='0' target='0' unit='0'/>
>    </disk>
>    <controller type='usb' index='0'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
>    </controller>
>    <controller type='ide' index='0'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x1'/>
>    </controller>
>    <controller type='virtio-serial' index='0'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
>    </controller>
>    <interface type='network'>
>      <mac address='52:54:00:37:f1:84'/>
>      <source network='default'/>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
>    </interface>
>    <serial type='pty'>
>      <target port='0'/>
>    </serial>
>    <console type='pty'>
>      <target type='serial' port='0'/>
>    </console>
>    <channel type='spicevmc'>
>      <target type='virtio' name='com.redhat.spice.0'/>
>      <address type='virtio-serial' controller='0' bus='0' port='1'/>
>    </channel>
>    <input type='mouse' bus='ps2'/>
>    <graphics type='spice' autoport='yes'/>
>    <sound model='ich6'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
>    </sound>
>    <video>
>      <model type='qxl' ram='65536' vram='65536' heads='1'/>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
>    </video>
>    <memballoon model='virtio'>
>      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>
>    </memballoon>
>  <rng model='virtio'>
>    <backend model='random'/>
>  </rng>
>  </devices>
></domain>
>
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=4 w=5, f=13 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=6 w=7, f=15 e=0 d=0
>2013-03-07 08:36:17.590+000023450: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c0007c60
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=7 w=8, f=15 e=1 d=0
>2013-03-07 08:36:17.590+000023450: debug : virObjectRef:295 : OBJECT_REF: obj=0x7f99c021ce80
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=8 w=9, f=17 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollMakePollFDs:393 : Prepare n=9 w=11, f=19 e=1 d=0
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 2 timers
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1362645382590
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1362645382590 now=1362645377590
>2013-03-07 08:36:17.590+000023447: debug : virEventPollCalculateTimeout:361 : Timeout at 1362645382590 due in 5000 ms
>2013-03-07 08:36:17.590+000023447: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=9 timeout=5000
>
>
>     ====== end of log =====
>

Actions: View

Attachments on bug 919004: 706535 | 706536