Attachment 622165 Details for Bug 862756 – libvirtd.log

libvirtd.log

libvirtd.log (text/plain), 65.89 KB, created by David Jaša on 2012-10-05 13:18:09 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: David Jaša

Created: 2012-10-05 13:18:09 UTC

Size: 65.89 KB

patch

obsolete

>2012-10-05 13:09:58.333+0000: 20208: debug : qemuProcessStart:3518 : Checking for CDROM and floppy presence
>2012-10-05 13:09:58.333+0000: 20208: debug : qemuProcessStart:3542 : Setting up domain cgroup (if required)
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupNew:617 : New group /libvirt/qemu/fedora
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 0:cpu at /cgroup/cpu in 
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 1:cpuacct at /cgroup/cpuacct in 
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 2:cpuset at /cgroup/cpuset in 
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 3:memory at /cgroup/memory in 
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 4:devices at /cgroup/devices in 
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 5:freezer at /cgroup/freezer in 
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 6:blkio at /cgroup/blkio in 
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupMakeGroup:535 : Make group /libvirt/qemu/fedora
>2012-10-05 13:09:58.333+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/cpu/libvirt/qemu/fedora/
>2012-10-05 13:09:58.335+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/cpuacct/libvirt/qemu/fedora/
>2012-10-05 13:09:58.335+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/cpuset/libvirt/qemu/fedora/
>2012-10-05 13:09:58.335+0000: 20208: debug : virCgroupCpuSetInherit:469 : Setting up inheritance /libvirt/qemu -> /libvirt/qemu/fedora
>2012-10-05 13:09:58.335+0000: 20208: debug : virCgroupGetValueStr:361 : Get value /cgroup/cpuset/libvirt/qemu/cpuset.cpus
>2012-10-05 13:09:58.336+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupCpuSetInherit:482 : Inherit cpuset.cpus = 0-3
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/cpuset/libvirt/qemu/fedora/cpuset.cpus' to '0-3'
>2012-10-05 13:09:58.336+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupGetValueStr:361 : Get value /cgroup/cpuset/libvirt/qemu/cpuset.mems
>2012-10-05 13:09:58.336+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupCpuSetInherit:482 : Inherit cpuset.mems = 0
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/cpuset/libvirt/qemu/fedora/cpuset.mems' to '0'
>2012-10-05 13:09:58.336+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/memory/libvirt/qemu/fedora/
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupGetValueStr:361 : Get value /cgroup/memory/libvirt/qemu/fedora/memory.use_hierarchy
>2012-10-05 13:09:58.336+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupSetMemoryUseHierarchy:517 : Setting up /libvirt/qemu/fedora/memory.use_hierarchy
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/memory/libvirt/qemu/fedora/memory.use_hierarchy' to '1'
>2012-10-05 13:09:58.336+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/devices/libvirt/qemu/fedora/
>2012-10-05 13:09:58.336+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/freezer/libvirt/qemu/fedora/
>2012-10-05 13:09:58.337+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/blkio/libvirt/qemu/fedora/
>2012-10-05 13:09:58.337+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.deny' to 'a'
>2012-10-05 13:09:58.337+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.337+0000: 20208: debug : qemuSetupDiskPathAllow:70 : Process path /dev/root_vg/fedora-virt for disk
>2012-10-05 13:09:58.338+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'b 253:6 rw'
>2012-10-05 13:09:58.338+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.338+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.338+0000: 20208: debug : qemuSetupDiskPathAllow:70 : Process path /home/david/virt/bfo.iso for disk
>2012-10-05 13:09:58.339+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.339+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 136:* rw'
>2012-10-05 13:09:58.339+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.339+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 1:3 rw'
>2012-10-05 13:09:58.339+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.339+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 1:7 rw'
>2012-10-05 13:09:58.339+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.339+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 1:5 rw'
>2012-10-05 13:09:58.339+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.339+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 1:8 rw'
>2012-10-05 13:09:58.339+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.340+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 1:9 rw'
>2012-10-05 13:09:58.340+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.340+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 5:2 rw'
>2012-10-05 13:09:58.340+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.340+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 10:232 rw'
>2012-10-05 13:09:58.340+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.340+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 254:0 rw'
>2012-10-05 13:09:58.340+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.340+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/devices/libvirt/qemu/fedora/devices.allow' to 'c 10:228 rw'
>2012-10-05 13:09:58.340+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.340+0000: 20208: debug : virCgroupSetValueStr:331 : Set value '/cgroup/memory/libvirt/qemu/fedora/memory.limit_in_bytes' to '2468598784'
>2012-10-05 13:09:58.340+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.340+0000: 20208: debug : qemuProcessStart:3551 : Preparing monitor state
>2012-10-05 13:09:58.340+0000: 20208: debug : qemuProcessStart:3587 : Assigning domain PCI addresses
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:5.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.1 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.2 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.3 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.4 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.5 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.6 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.7 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:3.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.1 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.2 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.3 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.4 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.5 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.6 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.7 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:4.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.1 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.2 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.3 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.4 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.5 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.6 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.7 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:2.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.1 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.2 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.3 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.4 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.5 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.6 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.7 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:7.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:7.1 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:7.2 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:7.3 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:7.4 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:7.5 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:7.6 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:7.7 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:1.1
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:8.7
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:8.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:8.1
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:8.2
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:6.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:6.1 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:6.2 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:6.3 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:6.4 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:6.5 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:6.6 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:6.7 (multifunction=off for function 0)
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.0
>2012-10-05 13:09:58.341+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.1
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.2
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.3
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.4
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.5
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.6
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.7
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.0
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.2
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.3
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.4
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.5
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.6
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.7
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuProcessStart:3592 : Building emulator command line
>2012-10-05 13:09:58.342+0000: 20208: debug : qemuBuildCommandLine:4470 : conn=0x7fd674000c20 driver=0x7fd684011c50 def=0x7fd684194010 mon=0x7fd6841a6c70 json=1 caps=0x7fd6840f22b0 migrateFrom=(null) migrateFD=-1 snapshot=(nil) vmop=0
>2012-10-05 13:09:58.342+0000: 20208: debug : cpuDataFree:212 : arch=x86_64, data=(nil)
>2012-10-05 13:09:58.342+0000: 20208: debug : networkAllocateActualDevice:3669 : Using network default, 1 connections
>2012-10-05 13:09:58.342+0000: 20208: info : virNetDevProbeVnetHdr:94 : Enabling IFF_VNET_HDR
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=8 events=1
>2012-10-05 13:09:58.353+0000: 20207: debug : virNetlinkEventCallback:346 : dispatching to max 0 clients, called from event watch 8
>2012-10-05 13:09:58.353+0000: 20207: debug : virNetlinkEventCallback:359 : event not handled.
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4868 ms
>2012-10-05 13:09:58.353+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4868
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=8 events=1
>2012-10-05 13:09:58.355+0000: 20207: debug : virNetlinkEventCallback:346 : dispatching to max 0 clients, called from event watch 8
>2012-10-05 13:09:58.355+0000: 20207: debug : virNetlinkEventCallback:359 : event not handled.
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4866 ms
>2012-10-05 13:09:58.355+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4866
>2012-10-05 13:09:58.356+0000: 20208: debug : virFileClose:72 : Closed fd 25
>2012-10-05 13:09:58.356+0000: 20208: debug : virFileClose:72 : Closed fd 25
>2012-10-05 13:09:58.356+0000: 20208: debug : virFileClose:72 : Closed fd 25
>2012-10-05 13:09:58.364+0000: 20208: debug : virFileClose:72 : Closed fd 25
>2012-10-05 13:09:58.365+0000: 20208: debug : virFileClose:72 : Closed fd 25
>2012-10-05 13:09:58.366+0000: 20208: debug : qemuProcessStart:3637 : Clear emulator capabilities: 1
>2012-10-05 13:09:58.366+0000: 20208: debug : virCommandRequireHandshake:2488 : Transfer handshake wait=27 notify=28, keep handshake wait=26 notify=29
>2012-10-05 13:09:58.366+0000: 20208: debug : virCommandRunAsync:2209 : About to run LC_ALL=C PATH=/sbin:/usr/sbin:/bin:/usr/bin QEMU_AUDIO_DRV=spice /usr/libexec/qemu-kvm -name fedora -S -M rhel6.3.0 -enable-kvm -m 2048 -smp 3,sockets=3,cores=1,threads=1 -uuid 392ce819-48d4-0856-14b6-c2f28f4093e7 -nodefconfig -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/fedora.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -boot menu=off -kernel /mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz -initrd /mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img -append repo=http://download.englab.brq.redhat.com//mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x7 -device ich9-usb-ehci1,id=usb,bus=pci.0,multifunction=on,addr=0x8.0x7 -device ich9-usb-uhci1,masterbus=usb.0,firstport=0,bus=pci.0,multifunction=on,addr=0x8 -device ich9-usb-uhci2,masterbus=usb.0,firstport=2,bus=pci.0,multifunction=on,addr=0x8.0x1 -device ich9-usb-uhci3,masterbus=usb.0,firstport=4,bus=pci.0,multifunction=on,addr=0x8.0x2 -device usb-ccid,id=ccid0 -drive file=/dev/root_vg/fedora-virt,if=none,id=drive-virtio-disk0,format=raw,cache=none,aio=native -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x5,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -drive file=/home/david/virt/bfo.iso,if=none,media=cdrom,id=drive-ide0-1-0,readonly=on,format=raw,cache=none -device ide-drive,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0 -netdev tap,fd=24,id=hostnet0,vhost=on,vhostfd=25 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:f6:14:85,bus=pci.0,addr=0x3 -chardev spicevmc,id=charsmartcard0,name=smartcard -device ccid-card-passthru,chardev=charsmartcard0,id=smartcard0,bus=ccid0.0 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -spice port=3003,addr=::0,disable-ticketing,x509-dir=/etc/pki/libvirt-spice -vga qxl -global qxl-vga.vram_size=67108864 -device intel-hda,id=sound0,bus=pci.0,addr=0x4 -device hda-duplex,id=sound0-codec0,bus=sound0.0,cad=0 -chardev spicevmc,id=charredir0,name=usbredir -device usb-redir,chardev=charredir0,id=redir0,bus=usb.0,port=3 -chardev spicevmc,id=charredir1,name=usbredir -device usb-redir,chardev=charredir1,id=redir1,bus=usb.0,port=4 -chardev spicevmc,id=charredir2,name=usbredir -device usb-redir,chardev=charredir2,id=redir2,bus=usb.0,port=5 -chardev spicevmc,id=charredir3,name=usbredir -device usb-redir,chardev=charredir3,id=redir3,bus=usb.0,port=6 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x6
>2012-10-05 13:09:58.367+0000: 20208: debug : virFileClose:72 : Closed fd 30
>2012-10-05 13:09:58.367+0000: 20208: debug : virCommandRunAsync:2227 : Command result 0, with PID 20284
>2012-10-05 13:09:58.367+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.367+0000: 20208: debug : virFileClose:72 : Closed fd 25
>2012-10-05 13:09:58.367+0000: 20208: debug : virFileClose:72 : Closed fd 27
>2012-10-05 13:09:58.367+0000: 20208: debug : virFileClose:72 : Closed fd 28
>2012-10-05 13:09:58.370+0000: 20208: debug : virCommandRun:2025 : Result status 0, stdout: '(null)' stderr: '(null)'
>2012-10-05 13:09:58.370+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.370+0000: 20208: debug : qemuProcessStart:3684 : Writing early domain status to disk
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.426+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-10-05 13:09:58.427+0000: 20207: debug : udevEventHandleCallback:1467 : udev action: 'add'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevGetDeviceProperty:120 : udev reports device 'vnet0' does not have property 'DRIVER'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevGetDeviceType:1095 : Found device type '(null)' for device 'vnet0'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevGetDeviceProperty:120 : udev reports device 'vnet0' does not have property 'PCI_CLASS'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevGetDeviceProperty:140 : Found property key 'INTERFACE' value 'vnet0' for device with sysname 'vnet0'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevGetDeviceProperty:140 : Found property key 'INTERFACE' value 'vnet0' for device with sysname 'vnet0'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevGetDeviceSysfsAttr:229 : Found sysfs attribute 'address' value 'fe:54:00:f6:14:85' for device with sysname 'vnet0'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevGetDeviceSysfsAttr:229 : Found sysfs attribute 'addr_len' value '6' for device with sysname 'vnet0'
>2012-10-05 13:09:58.427+0000: 20207: debug : udevStrToLong_ui:84 : Converted '6' to unsigned int 6
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4794 ms
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4794
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.427+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-10-05 13:09:58.428+0000: 20207: debug : udevEventHandleCallback:1467 : udev action: 'add'
>2012-10-05 13:09:58.428+0000: 20207: debug : udevGetDeviceProperty:120 : udev reports device 'tx-0' does not have property 'DRIVER'
>2012-10-05 13:09:58.428+0000: 20207: debug : udevGetDeviceType:1095 : Found device type '(null)' for device 'tx-0'
>2012-10-05 13:09:58.428+0000: 20207: debug : udevGetDeviceProperty:120 : udev reports device 'tx-0' does not have property 'PCI_CLASS'
>2012-10-05 13:09:58.428+0000: 20207: debug : udevGetDeviceProperty:120 : udev reports device 'tx-0' does not have property 'INTERFACE'
>2012-10-05 13:09:58.428+0000: 20207: debug : udevGetDeviceType:1152 : Could not determine device type for device with sysfs path 'tx-0'
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4793 ms
>2012-10-05 13:09:58.428+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4793
>2012-10-05 13:09:58.456+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.456+0000: 20208: debug : qemuProcessStart:3689 : Waiting for handshake from child
>2012-10-05 13:09:58.456+0000: 20208: debug : virCommandHandshakeWait:2521 : Wait for handshake on 26
>2012-10-05 13:09:58.456+0000: 20208: debug : virFileClose:72 : Closed fd 26
>2012-10-05 13:09:58.456+0000: 20208: debug : qemuProcessStart:3694 : Setting domain security labels
>2012-10-05 13:09:58.456+0000: 20208: info : virSecuritySELinuxSetFileconHelper:754 : Setting SELinux context on '/dev/root_vg/fedora-virt' to 'unconfined_u:object_r:svirt_image_t:s0:c669,c876'
>2012-10-05 13:09:58.457+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.457+0000: 20208: info : virSecuritySELinuxSetFileconHelper:754 : Setting SELinux context on '/home/david/virt/bfo.iso' to 'system_u:object_r:virt_content_t:s0'
>2012-10-05 13:09:58.460+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.460+0000: 20208: info : virSecuritySELinuxSetFileconHelper:754 : Setting SELinux context on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz' to 'system_u:object_r:virt_content_t:s0'
>2012-10-05 13:09:58.499+0000: 20208: debug : virStorageFileIsSharedFSType:1033 : Check if path /mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz with FS magic 26985 is shared
>2012-10-05 13:09:58.499+0000: 20208: warning : virSecuritySELinuxSetFileconHelper:788 : Setting security context 'system_u:object_r:virt_content_t:s0' on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz' not supported. Consider setting virt_use_nfs
>2012-10-05 13:09:58.499+0000: 20208: info : virSecuritySELinuxSetFileconHelper:754 : Setting SELinux context on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img' to 'system_u:object_r:virt_content_t:s0'
>2012-10-05 13:09:58.510+0000: 20208: debug : virStorageFileIsSharedFSType:1033 : Check if path /mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img with FS magic 26985 is shared
>2012-10-05 13:09:58.510+0000: 20208: warning : virSecuritySELinuxSetFileconHelper:788 : Setting security context 'system_u:object_r:virt_content_t:s0' on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img' not supported. Consider setting virt_use_nfs
>2012-10-05 13:09:58.510+0000: 20208: info : virSecurityDACSetOwnership:256 : Setting DAC user and group on '/dev/root_vg/fedora-virt' to '107:107'
>2012-10-05 13:09:58.510+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.510+0000: 20208: info : virSecurityDACSetOwnership:256 : Setting DAC user and group on '/home/david/virt/bfo.iso' to '107:107'
>2012-10-05 13:09:58.510+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:58.510+0000: 20208: info : virSecurityDACSetOwnership:256 : Setting DAC user and group on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz' to '107:107'
>2012-10-05 13:09:58.524+0000: 20208: info : virSecurityDACSetOwnership:273 : Setting user and group to '107:107' on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz' not supported by filesystem
>2012-10-05 13:09:58.524+0000: 20208: info : virSecurityDACSetOwnership:256 : Setting DAC user and group on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img' to '107:107'
>2012-10-05 13:09:58.539+0000: 20208: info : virSecurityDACSetOwnership:273 : Setting user and group to '107:107' on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img' not supported by filesystem
>2012-10-05 13:09:58.539+0000: 20208: debug : qemuProcessStart:3723 : Labelling done, completing handshake to child
>2012-10-05 13:09:58.539+0000: 20208: debug : virCommandHandshakeNotify:2588 : Notify handshake on 29
>2012-10-05 13:09:58.539+0000: 20208: debug : virFileClose:72 : Closed fd 29
>2012-10-05 13:09:58.539+0000: 20208: debug : qemuProcessStart:3727 : Handshake complete, child running
>2012-10-05 13:09:58.539+0000: 20208: debug : qemuProcessStart:3738 : Waiting for monitor to show up
>2012-10-05 13:09:58.740+0000: 20208: debug : qemuProcessWaitForMonitor:1613 : Connect monitor to 0x7fd6841a1680 'fedora'
>2012-10-05 13:09:58.741+0000: 20208: debug : virSecuritySELinuxSetSecurityDaemonSocketLabel:1639 : Setting VM fedora socket context unconfined_u:system_r:virtd_t:s0:c669,c876
>2012-10-05 13:09:58.742+0000: 20208: debug : virObjectRef:168 : OBJECT_REF: obj=0x7fd6841a1680
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=8 events=1
>2012-10-05 13:09:58.753+0000: 20207: debug : virNetlinkEventCallback:346 : dispatching to max 0 clients, called from event watch 8
>2012-10-05 13:09:58.753+0000: 20207: debug : virNetlinkEventCallback:359 : event not handled.
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.753+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4467 ms
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4467
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=8 events=1
>2012-10-05 13:09:58.754+0000: 20207: debug : virNetlinkEventCallback:346 : dispatching to max 0 clients, called from event watch 8
>2012-10-05 13:09:58.754+0000: 20207: debug : virNetlinkEventCallback:359 : event not handled.
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.754+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4466 ms
>2012-10-05 13:09:58.755+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4466
>2012-10-05 13:09:58.760+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-10-05 13:09:58.761+0000: 20207: debug : udevEventHandleCallback:1467 : udev action: 'remove'
>2012-10-05 13:09:58.761+0000: 20207: debug : udevRemoveOneDevice:1218 : Failed to find device to remove that has udev name '/sys/devices/virtual/net/vnet0/queues/tx-0'
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.761+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4460 ms
>2012-10-05 13:09:58.762+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4460
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:58.807+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-10-05 13:09:58.808+0000: 20207: debug : udevEventHandleCallback:1467 : udev action: 'remove'
>2012-10-05 13:09:58.808+0000: 20207: debug : udevRemoveOneDevice:1214 : Removing device 'net_vnet0_fe_54_00_f6_14_85' with sysfs path '/sys/devices/virtual/net/vnet0'
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=6 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=8, f=17 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=9, f=18 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollMakePollFDs:378 : Prepare n=9 w=10, f=20 e=1 d=0
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1349442603221
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollCalculateTimeout:346 : Timeout at 1349442603221 due in 4413 ms
>2012-10-05 13:09:58.808+0000: 20207: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=10 timeout=4413
>2012-10-05 13:09:59.152+0000: 20208: error : qemuMonitorOpenUnix:293 : failed to connect to monitor socket: Tento proces neexistuje
>2012-10-05 13:09:59.152+0000: 20208: debug : virFileClose:72 : Closed fd 25
>2012-10-05 13:09:59.153+0000: 20208: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7fd6841a1680
>2012-10-05 13:09:59.153+0000: 20208: info : qemuConnectMonitor:1260 : Failed to connect monitor for fedora
>2012-10-05 13:09:59.153+0000: 20208: error : qemuProcessWaitForMonitor:1644 : vnitÅnÃ chyba process exited while connecting to monitor: 2012-10-05 13:09:58.368+0000: 20284: debug : virFileClose:72 : Closed fd 23
>2012-10-05 13:09:58.368+0000: 20284: debug : virFileClose:72 : Closed fd 30
>2012-10-05 13:09:58.369+0000: 20284: debug : virFileClose:72 : Closed fd 3
>char device redirected to /dev/pts/13
>qemu: could not load kernel '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz': Permission denied
>
>2012-10-05 13:09:59.153+0000: 20208: debug : virFileClose:72 : Closed fd 24
>2012-10-05 13:09:59.153+0000: 20208: debug : virFileClose:72 : Closed fd 23
>2012-10-05 13:09:59.153+0000: 20208: debug : qemuProcessStop:3986 : Shutting down VM 'fedora' pid=20285 flags=0
>2012-10-05 13:09:59.154+0000: 20208: debug : virFileClose:72 : Closed fd 23
>2012-10-05 13:09:59.154+0000: 20208: debug : qemuProcessKill:3884 : vm=fedora pid=20285 flags=5
>2012-10-05 13:09:59.154+0000: 20208: debug : qemuDomainCleanupRun:1989 : driver=0x7fd684011c50, vm=fedora
>2012-10-05 13:09:59.154+0000: 20208: debug : qemuProcessAutoDestroyRemove:4459 : vm=fedora
>2012-10-05 13:09:59.154+0000: 20208: debug : qemuDriverCloseCallbackUnset:661 : vm=fedora, uuid=392ce819-48d4-0856-14b6-c2f28f4093e7, cb=0x4ad940
>2012-10-05 13:09:59.154+0000: 20208: debug : virSecuritySELinuxRestoreSecurityAllLabel:1408 : Restoring security label on fedora
>2012-10-05 13:09:59.154+0000: 20208: info : virSecuritySELinuxRestoreSecurityFileLabel:884 : Restoring SELinux context on '/dev/root_vg/fedora-virt'
>2012-10-05 13:09:59.253+0000: 20208: info : virSecuritySELinuxSetFileconHelper:754 : Setting SELinux context on '/dev/dm-6' to 'system_u:object_r:fixed_disk_device_t:s0'
>2012-10-05 13:09:59.253+0000: 20208: info : virSecuritySELinuxRestoreSecurityFileLabel:884 : Restoring SELinux context on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz'
>2012-10-05 13:09:59.345+0000: 20208: warning : virSecuritySELinuxRestoreSecurityFileLabel:899 : cannot lookup default selinux label for /mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz
>2012-10-05 13:09:59.345+0000: 20208: info : virSecuritySELinuxRestoreSecurityFileLabel:884 : Restoring SELinux context on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img'
>2012-10-05 13:09:59.436+0000: 20208: warning : virSecuritySELinuxRestoreSecurityFileLabel:899 : cannot lookup default selinux label for /mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img
>2012-10-05 13:09:59.436+0000: 20208: debug : virSecurityDACRestoreSecurityAllLabel:710 : Restoring security label on fedora migrated=0
>2012-10-05 13:09:59.436+0000: 20208: info : virSecurityDACRestoreSecurityFileLabel:300 : Restoring DAC user and group on '/dev/root_vg/fedora-virt'
>2012-10-05 13:09:59.436+0000: 20208: info : virSecurityDACSetOwnership:256 : Setting DAC user and group on '/dev/dm-6' to '0:0'
>2012-10-05 13:09:59.436+0000: 20208: info : virSecurityDACRestoreSecurityFileLabel:300 : Restoring DAC user and group on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz'
>2012-10-05 13:09:59.436+0000: 20208: info : virSecurityDACSetOwnership:256 : Setting DAC user and group on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz' to '0:0'
>2012-10-05 13:09:59.447+0000: 20208: info : virSecurityDACSetOwnership:273 : Setting user and group to '0:0' on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/vmlinuz' not supported by filesystem
>2012-10-05 13:09:59.447+0000: 20208: info : virSecurityDACRestoreSecurityFileLabel:300 : Restoring DAC user and group on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img'
>2012-10-05 13:09:59.447+0000: 20208: info : virSecurityDACSetOwnership:256 : Setting DAC user and group on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img' to '0:0'
>2012-10-05 13:09:59.463+0000: 20208: info : virSecurityDACSetOwnership:273 : Setting user and group to '0:0' on '/mnt/globalsync/pub/fedora/fedora-alt/stage/18-Beta-TC1/Fedora/x86_64/os/isolinux/initrd.img' not supported by filesystem
>2012-10-05 13:09:59.463+0000: 20208: debug : networkReleaseActualDevice:3900 : Nothing to release to network default
>2012-10-05 13:09:59.463+0000: 20208: debug : networkReleaseActualDevice:3986 : Releasing network default, 0 connections
>2012-10-05 13:09:59.463+0000: 20208: debug : virCgroupNew:617 : New group /libvirt/qemu/fedora
>2012-10-05 13:09:59.464+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 0:cpu at /cgroup/cpu in 
>2012-10-05 13:09:59.464+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 1:cpuacct at /cgroup/cpuacct in 
>2012-10-05 13:09:59.464+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 2:cpuset at /cgroup/cpuset in 
>2012-10-05 13:09:59.464+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 3:memory at /cgroup/memory in 
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 4:devices at /cgroup/devices in 
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 5:freezer at /cgroup/freezer in 
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupDetect:273 : Detected mount/mapping 6:blkio at /cgroup/blkio in 
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:535 : Make group /libvirt/qemu/fedora
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/cpu/libvirt/qemu/fedora/
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/cpuacct/libvirt/qemu/fedora/
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/cpuset/libvirt/qemu/fedora/
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/memory/libvirt/qemu/fedora/
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/devices/libvirt/qemu/fedora/
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/freezer/libvirt/qemu/fedora/
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupMakeGroup:560 : Make controller /cgroup/blkio/libvirt/qemu/fedora/
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupRemove:772 : Removing cgroup /cgroup/cpu/libvirt/qemu/fedora/ and all child cgroups
>2012-10-05 13:09:59.465+0000: 20208: debug : virCgroupRemoveRecursively:727 : Removing cgroup /cgroup/cpu/libvirt/qemu/fedora/
>2012-10-05 13:09:59.472+0000: 20208: debug : virCgroupRemove:772 : Removing cgroup /cgroup/cpuacct/libvirt/qemu/fedora/ and all child cgroups
>2012-10-05 13:09:59.472+0000: 20208: debug : virCgroupRemoveRecursively:727 : Removing cgroup /cgroup/cpuacct/libvirt/qemu/fedora/
>2012-10-05 13:09:59.484+0000: 20208: debug : virCgroupRemove:772 : Removing cgroup /cgroup/cpuset/libvirt/qemu/fedora/ and all child cgroups
>2012-10-05 13:09:59.484+0000: 20208: debug : virCgroupRemoveRecursively:727 : Removing cgroup /cgroup/cpuset/libvirt/qemu/fedora/
>2012-10-05 13:09:59.492+0000: 20208: debug : virCgroupRemove:772 : Removing cgroup /cgroup/memory/libvirt/qemu/fedora/ and all child cgroups
>2012-10-05 13:09:59.492+0000: 20208: debug : virCgroupRemoveRecursively:727 : Removing cgroup /cgroup/memory/libvirt/qemu/fedora/
>2012-10-05 13:09:59.500+0000: 20208: debug : virCgroupRemove:772 : Removing cgroup /cgroup/devices/libvirt/qemu/fedora/ and all child cgroups
>2012-10-05 13:09:59.500+0000: 20208: debug : virCgroupRemoveRecursively:727 : Removing cgroup /cgroup/devices/libvirt/qemu/fedora/
>2012-10-05 13:09:59.508+0000: 20208: debug : virCgroupRemove:772 : Removing cgroup /cgroup/freezer/libvirt/qemu/fedora/ and all child cgroups
>2012-10-05 13:09:59.508+0000: 20208: debug : virCgroupRemoveRecursively:727 : Removing cgroup /cgroup/freezer/libvirt/qemu/fedora/
>2012-10-05 13:09:59.516+0000: 20208: debug : virCgroupRemove:772 : Removing cgroup /cgroup/blkio/libvirt/qemu/fedora/ and all child cgroups
>2012-10-05 13:09:59.516+0000: 20208: debug : virCgroupRemoveRecursively:727 : Removing cgroup /cgroup/blkio/libvirt/qemu/fedora/
>2012-10-05 13:09:59.528+0000: 20208: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7fd6840f22b0
>2012-10-05 13:09:59.528+0000: 20208: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x7fd6840f22b0
>2012-10-05 13:09:59.528+0000: 20208: debug : qemuDomainObjEndJob:936 : Stopping job: modify (async=none)
>2012-10-05 13:09:59.528+0000: 20208: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7fd6841a1680
>2012-10-05 13:09:59.528+0000: 20208: debug : virDomainFree:2281 : dom=0x7fd6841a3460, (VM: name=fedora, uuid=392ce819-48d4-0856-14b6-c2f28f4093e7)
>2012-10-05 13:09:59.528+0000: 20208: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7fd6841a3460
>2012-10-05 13:09:59.528+0000: 20208: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x7fd6841a3460
>2012-10-05 13:09:59.529+0000: 20208: debug : virDomainDispose:225 : release domain 0x7fd6841a3460 fedora 392ce819-48d4-0856-14b6-c2f28f4093e7
>2012-10-05 13:09:59.529+0000: 20208: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7fd674000c20
>2012-10-05 13:09:59.529+0000: 20208: debug : virNetServerProgramSendError:150 : prog=536903814 ver=1 proc=9 type=1 serial=5 msg=0x7ee8b0 rerr=0x7fd68f2d2b80
>2012-10-05 13:09:59.529+0000: 20208: debug : virNetMessageEncodePayload:358 : Encode length as 1016
>2012-10-05 13:09:59.529+0000: 20208: debug : virNetServerClientSendMessageLocked:1116 : msg=0x7ee8b0 proc=9 len=1016 offset=0
>2012-10-05 13:09:59.529+0000: 20208: debug : virNetServerClientSendMessageLocked:1124 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7f00f0 len=1016 prog=536903814 vers=1 proc=9 type=1 status=1 serial=5
>2012-10-05 13:09:59.529+0000: 20208: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x7ed890 tx=0x7ee8b0
>2012-10-05 13:09:59.529+0000: 20208: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2012-10-05 13:09:59.529+0000: 20208: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=10 events=3
>2012-10-05 13:09:59.529+0000: 20208: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchTimeouts:410 : Dispatch 2
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:455 : Dispatch 10
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=7 w=8
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=8 w=9
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollDispatchHandles:469 : i=9 w=10
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollCleanupTimeouts:501 : Cleanup 2
>2012-10-05 13:09:59.529+0000: 20207: debug : virEventPollCleanupHandles:549 : Cleanup 10

Actions: View

Attachments on bug 862756: 622165