Attachment 617362 Details for Bug 844408 – libvirtd.log with filter qemu of debug log

libvirtd.log with filter qemu of debug log

libvirtd.log-attach-disk (text/plain), 75.30 KB, created by weizhang on 2012-09-26 02:43:22 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: weizhang

Created: 2012-09-26 02:43:22 UTC

Size: 75.30 KB

patch

obsolete

>2012-09-26 02:39:31.058+0000: 27521: info : libvirt version: 0.10.2, package: 1.el6 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2012-09-24-04:06:26, x86-009.build.bos.redhat.com)
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendVolOpenCheckMode:1023 : cannot stat file '/tmp/snapshot-c.qcow2': No such file or directory
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendFileSystemRefresh:896 : internal error cannot probe backing volume info: /tmp/snapshot-c.qcow2
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendVolOpenCheckMode:1023 : cannot stat file '/tmp/snapshot-a.qcow2': No such file or directory
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendFileSystemRefresh:896 : internal error cannot probe backing volume info: /tmp/snapshot-a.qcow2
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendVolOpenCheckMode:1023 : cannot stat file '/tmp/snapshot-b.qcow2': No such file or directory
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendFileSystemRefresh:896 : internal error cannot probe backing volume info: /tmp/snapshot-b.qcow2
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendVolOpenCheckMode:1023 : cannot stat file '/tmp/snapshot-a.qcow2': No such file or directory
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendFileSystemRefresh:896 : internal error cannot probe backing volume info: /tmp/snapshot-a.qcow2
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageFileProbeFormat:798 : cannot open file '/var/lib/libvirt/migrate/RHEL-Server-6.3-64-virtio.qcow2': No such file or directory
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendProbeTarget:118 : internal error cannot probe backing volume format: /var/lib/libvirt/migrate/RHEL-Server-6.3-64-virtio.qcow2
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendVolOpenCheckMode:1023 : cannot stat file '/var/lib/libvirt/migrate/RHEL-Server-6.3-64-virtio.qcow2': No such file or directory
>2012-09-26 02:39:31.058+0000: 27521: error : virStorageBackendFileSystemRefresh:896 : internal error cannot probe backing volume info: /var/lib/libvirt/migrate/RHEL-Server-6.3-64-virtio.qcow2
>2012-09-26 02:39:31.073+0000: 27521: error : virStorageBackendVolOpenCheckMode:1023 : cannot stat file '/tmp/snapshot-b.qcow2': No such file or directory
>2012-09-26 02:39:31.073+0000: 27521: error : virStorageBackendFileSystemRefresh:896 : internal error cannot probe backing volume info: /tmp/snapshot-b.qcow2
>2012-09-26 02:39:31.076+0000: 27521: error : virStorageBackendVolOpenCheckMode:1023 : cannot stat file '/tmp/snapshot-c.qcow2': No such file or directory
>2012-09-26 02:39:31.076+0000: 27521: error : virStorageBackendFileSystemRefresh:896 : internal error cannot probe backing volume info: /tmp/snapshot-c.qcow2
>2012-09-26 02:39:31.151+0000: 27521: info : qemudLoadDriverConfig:411 : Configured cgroup controller 'cpu'
>2012-09-26 02:39:31.151+0000: 27521: info : qemudLoadDriverConfig:411 : Configured cgroup controller 'cpuacct'
>2012-09-26 02:39:31.151+0000: 27521: info : qemudLoadDriverConfig:411 : Configured cgroup controller 'cpuset'
>2012-09-26 02:39:31.151+0000: 27521: info : qemudLoadDriverConfig:411 : Configured cgroup controller 'memory'
>2012-09-26 02:39:31.151+0000: 27521: info : qemudLoadDriverConfig:411 : Configured cgroup controller 'devices'
>2012-09-26 02:39:31.151+0000: 27521: info : qemudLoadDriverConfig:411 : Configured cgroup controller 'blkio'
>2012-09-26 02:39:31.218+0000: 27521: debug : qemuCapsParseHelpStr:1445 : Version 0.12.1, cooked version 12001, flags 0x00010000000e5c000109fc6cf7effd6e
>2012-09-26 02:39:31.218+0000: 27521: debug : qemuCapsParseHelpStr:1451 : qemu-kvm version 0.12.1 detected
>2012-09-26 02:39:31.345+0000: 27521: debug : qemuCapsParseHelpStr:1445 : Version 0.12.1, cooked version 12001, flags 0x00010000000e5c000109fc6cf7effd6e
>2012-09-26 02:39:31.345+0000: 27521: debug : qemuCapsParseHelpStr:1451 : qemu-kvm version 0.12.1 detected
>2012-09-26 02:39:31.446+0000: 27521: debug : qemuCreateCapabilities:378 : Initialized caps for security driver "selinux" with DOI "0"
>2012-09-26 02:39:31.446+0000: 27521: debug : qemuCreateCapabilities:378 : Initialized caps for security driver "dac" with DOI "0"
>2012-09-26 02:39:31.452+0000: 27521: debug : qemuDomainObjBeginJobInternal:807 : Starting job: modify (async=none)
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain demo in /var/lib/libvirt/qemu/snapshot/demo
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain double-screen in /var/lib/libvirt/qemu/snapshot/double-screen
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest2 in /var/lib/libvirt/qemu/snapshot/guest2
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest1 in /var/lib/libvirt/qemu/snapshot/guest1
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain vr-rhel6-x86_64-kvm in /var/lib/libvirt/qemu/snapshot/vr-rhel6-x86_64-kvm
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain win7 in /var/lib/libvirt/qemu/snapshot/win7
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain rhel5u8-x86_64 in /var/lib/libvirt/qemu/snapshot/rhel5u8-x86_64
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain test in /var/lib/libvirt/qemu/snapshot/test
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest4 in /var/lib/libvirt/qemu/snapshot/guest4
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest11 in /var/lib/libvirt/qemu/snapshot/guest11
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain test1 in /var/lib/libvirt/qemu/snapshot/test1
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain pxe in /var/lib/libvirt/qemu/snapshot/pxe
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain vr-rhel6u2-x86_64-kvm in /var/lib/libvirt/qemu/snapshot/vr-rhel6u2-x86_64-kvm
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain kvm-rhel6u2-x86_64-new in /var/lib/libvirt/qemu/snapshot/kvm-rhel6u2-x86_64-new
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain domblkiotune in /var/lib/libvirt/qemu/snapshot/domblkiotune
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain rhel6u3 in /var/lib/libvirt/qemu/snapshot/rhel6u3
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain desktop in /var/lib/libvirt/qemu/snapshot/desktop
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain rhel5u8-i386 in /var/lib/libvirt/qemu/snapshot/rhel5u8-i386
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest5 in /var/lib/libvirt/qemu/snapshot/guest5
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain snapshot in /var/lib/libvirt/qemu/snapshot/snapshot
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:436 : Loading snapshot file '1331725041.xml'
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain demo1 in /var/lib/libvirt/qemu/snapshot/demo1
>2012-09-26 02:39:31.486+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest17 in /var/lib/libvirt/qemu/snapshot/guest17
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain rhel6 in /var/lib/libvirt/qemu/snapshot/rhel6
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain winxp-128M in /var/lib/libvirt/qemu/snapshot/winxp-128M
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain cdrom in /var/lib/libvirt/qemu/snapshot/cdrom
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain rhel6u12nd in /var/lib/libvirt/qemu/snapshot/rhel6u12nd
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest16 in /var/lib/libvirt/qemu/snapshot/guest16
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest13 in /var/lib/libvirt/qemu/snapshot/guest13
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest15 in /var/lib/libvirt/qemu/snapshot/guest15
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest8 in /var/lib/libvirt/qemu/snapshot/guest8
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest10 in /var/lib/libvirt/qemu/snapshot/guest10
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest14 in /var/lib/libvirt/qemu/snapshot/guest14
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest12 in /var/lib/libvirt/qemu/snapshot/guest12
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain rhevm in /var/lib/libvirt/qemu/snapshot/rhevm
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest3 in /var/lib/libvirt/qemu/snapshot/guest3
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest18 in /var/lib/libvirt/qemu/snapshot/guest18
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest7 in /var/lib/libvirt/qemu/snapshot/guest7
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest6 in /var/lib/libvirt/qemu/snapshot/guest6
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain vr-rhel6u3-x86_64-kvm in /var/lib/libvirt/qemu/snapshot/vr-rhel6u3-x86_64-kvm
>2012-09-26 02:39:31.487+0000: 27521: info : qemuDomainSnapshotLoad:436 : Loading snapshot file '1347351250.xml'
>2012-09-26 02:39:31.488+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain mig in /var/lib/libvirt/qemu/snapshot/mig
>2012-09-26 02:39:31.488+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest9 in /var/lib/libvirt/qemu/snapshot/guest9
>2012-09-26 02:39:31.488+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain usb in /var/lib/libvirt/qemu/snapshot/usb
>2012-09-26 02:39:31.488+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain kvm-rhel6u3-i386 in /var/lib/libvirt/qemu/snapshot/kvm-rhel6u3-i386
>2012-09-26 02:39:31.488+0000: 27521: info : qemuDomainSnapshotLoad:420 : Scanning for snapshots for domain guest19 in /var/lib/libvirt/qemu/snapshot/guest19
>2012-09-26 02:39:31.488+0000: 27597: debug : qemuProcessReconnect:3064 : Reconnect monitor to 0x7ffcec0084b0 'guest2'
>2012-09-26 02:39:31.488+0000: 27597: debug : qemuDomainObjTransferJob:189 : Changing job owner from 27521 to 27597
>2012-09-26 02:39:31.493+0000: 27521: debug : qemuDriverCloseCallbackRunAll:744 : conn=0x7ffcec1aa960
>2012-09-26 02:39:31.495+0000: 27597: debug : qemuMonitorOpenInternal:757 : QEMU_MONITOR_NEW: mon=0x7ffce4000cf0 refs=2 fd=23
>2012-09-26 02:39:31.495+0000: 27597: debug : qemuMonitorSetCapabilities:1133 : mon=0x7ffce4000cf0
>2012-09-26 02:39:31.495+0000: 27597: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"qmp_capabilities","id":"libvirt-1"}' for write with FD -1
>2012-09-26 02:39:31.495+0000: 27597: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce4000cf0 msg={"execute":"qmp_capabilities","id":"libvirt-1"}
> fd=-1
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce4000cf0 buf={"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}
> len=125
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 125 bytes out of 125 available in buffer
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce4000cf0 buf={"execute":"qmp_capabilities","id":"libvirt-1"}
> len=49 ret=49 errno=11
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce4000cf0 buf={"return": {}, "id": "libvirt-1"}
> len=35
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {}, "id": "libvirt-1"}]
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce4000cf0 reply={"return": {}, "id": "libvirt-1"}
>2012-09-26 02:39:31.495+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 35 bytes out of 35 available in buffer
>2012-09-26 02:39:31.495+0000: 27597: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x90d880
>2012-09-26 02:39:31.496+0000: 27597: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-commands","id":"libvirt-2"}' for write with FD -1
>2012-09-26 02:39:31.496+0000: 27597: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce4000cf0 msg={"execute":"query-commands","id":"libvirt-2"}
> fd=-1
>2012-09-26 02:39:31.496+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce4000cf0 buf={"execute":"query-commands","id":"libvirt-2"}
> len=47 ret=47 errno=11
>2012-09-26 02:39:31.497+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce4000cf0 buf={"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, len=1023
>2012-09-26 02:39:31.497+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 0 bytes out of 1023 available in buffer
>2012-09-26 02:39:31.498+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce4000cf0 buf={"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, {"name": "block-job-cancel"}, {"name": "query-version"}, {"name": "query-commands"}, {"name": "query-chardev"}, {"name": "query-block"}, {"name": "query-blockstats"}, {"name": "query-cpus"}, {"name": "query-kvm"}, {"name": "query-status"}, {"name": "query-mice"}, {"name": "query-vnc"}, {"name": "query-spice"}, {"name": "query-name"}, {"name": "query-uuid"}, {"name": "query-migrate"}, {"name": "query-balloon"}, {"name": "query-block-jobs"}], "id": "libvirt-2"}
> len=1489
>2012-09-26 02:39:31.498+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, {"name": "block-job-cancel"}, {"name": "query-version"}, {"name": "query-commands"}, {"name": "query-chardev"}, {"name": "query-block"}, {"name": "query-blockstats"}, {"name": "query-cpus"}, {"name": "query-kvm"}, {"name": "query-status"}, {"name": "query-mice"}, {"name": "query-vnc"}, {"name": "query-spice"}, {"name": "query-name"}, {"name": "query-uuid"}, {"name": "query-migrate"}, {"name": "query-balloon"}, {"name": "query-block-jobs"}], "id": "libvirt-2"}]
>2012-09-26 02:39:31.498+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce4000cf0 reply={"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, {"name": "block-job-cancel"}, {"name": "query-version"}, {"name": "query-commands"}, {"name": "query-chardev"}, {"name": "query-block"}, {"name": "query-blockstats"}, {"name": "query-cpus"}, {"name": "query-kvm"}, {"name": "query-status"}, {"name": "query-mice"}, {"name": "query-vnc"}, {"name": "query-spice"}, {"name": "query-name"}, {"name": "query-uuid"}, {"name": "query-migrate"}, {"name": "query-balloon"}, {"name": "query-block-jobs"}], "id": "libvirt-2"}
>2012-09-26 02:39:31.498+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 1489 bytes out of 1489 available in buffer
>2012-09-26 02:39:31.498+0000: 27597: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x90dc90
>2012-09-26 02:39:31.498+0000: 27597: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-events","id":"libvirt-3"}' for write with FD -1
>2012-09-26 02:39:31.498+0000: 27597: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce4000cf0 msg={"execute":"query-events","id":"libvirt-3"}
> fd=-1
>2012-09-26 02:39:31.499+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce4000cf0 buf={"execute":"query-events","id":"libvirt-3"}
> len=45 ret=45 errno=11
>2012-09-26 02:39:31.499+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce4000cf0 buf={"id": "libvirt-3", "error": {"class": "CommandNotFound", "desc": "The command query-events has not been found", "data": {"name": "query-events"}}}
> len=149
>2012-09-26 02:39:31.499+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"id": "libvirt-3", "error": {"class": "CommandNotFound", "desc": "The command query-events has not been found", "data": {"name": "query-events"}}}]
>2012-09-26 02:39:31.499+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce4000cf0 reply={"id": "libvirt-3", "error": {"class": "CommandNotFound", "desc": "The command query-events has not been found", "data": {"name": "query-events"}}}
>2012-09-26 02:39:31.499+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 149 bytes out of 149 available in buffer
>2012-09-26 02:39:31.499+0000: 27597: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x913d50
>2012-09-26 02:39:31.499+0000: 27597: debug : qemuMonitorGetStatus:1209 : mon=0x7ffce4000cf0, running=0x7ffcf38b6aff, reason=0x7ffcf38b6af4
>2012-09-26 02:39:31.499+0000: 27597: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-status","id":"libvirt-4"}' for write with FD -1
>2012-09-26 02:39:31.499+0000: 27597: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce4000cf0 msg={"execute":"query-status","id":"libvirt-4"}
> fd=-1
>2012-09-26 02:39:31.499+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce4000cf0 buf={"execute":"query-status","id":"libvirt-4"}
> len=45 ret=45 errno=11
>2012-09-26 02:39:31.500+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce4000cf0 buf={"return": {"status": "running", "singlestep": false, "running": true}, "id": "libvirt-4"}
> len=92
>2012-09-26 02:39:31.500+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {"status": "running", "singlestep": false, "running": true}, "id": "libvirt-4"}]
>2012-09-26 02:39:31.500+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce4000cf0 reply={"return": {"status": "running", "singlestep": false, "running": true}, "id": "libvirt-4"}
>2012-09-26 02:39:31.500+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 92 bytes out of 92 available in buffer
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x914780
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:4.0
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.1 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.2 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.3 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.4 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.5 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.6 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.7 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:3.0
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.1 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.2 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.3 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.4 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.5 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.6 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.7 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:2.0
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.1 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.2 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.3 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.4 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.5 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.6 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.7 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:1.2
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:5.0
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.1 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.2 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.3 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.4 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.5 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.6 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.7 (multifunction=off for function 0)
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.0
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.1
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.2
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.3
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.4
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.5
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.6
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.7
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.0
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.1
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.3
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.4
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.5
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.6
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.7
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuMonitorGetBlockInfo:1394 : mon=0x7ffce4000cf0
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-block","id":"libvirt-5"}' for write with FD -1
>2012-09-26 02:39:31.500+0000: 27597: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce4000cf0 msg={"execute":"query-block","id":"libvirt-5"}
> fd=-1
>2012-09-26 02:39:31.501+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce4000cf0 buf={"execute":"query-block","id":"libvirt-5"}
> len=44 ret=44 errno=11
>2012-09-26 02:39:31.501+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce4000cf0 buf={"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"ro": false, "drv": "raw", "encrypted": false, "file": "/var/lib/libvirt/images/kvm-rhel6u3-x86_64.img"}, "type": "unknown"}], "id": "libvirt-5"}
> len=261
>2012-09-26 02:39:31.501+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"ro": false, "drv": "raw", "encrypted": false, "file": "/var/lib/libvirt/images/kvm-rhel6u3-x86_64.img"}, "type": "unknown"}], "id": "libvirt-5"}]
>2012-09-26 02:39:31.501+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce4000cf0 reply={"return": [{"io-status": "ok", "device": "drive-virtio-disk0", "locked": false, "removable": false, "inserted": {"ro": false, "drv": "raw", "encrypted": false, "file": "/var/lib/libvirt/images/kvm-rhel6u3-x86_64.img"}, "type": "unknown"}], "id": "libvirt-5"}
>2012-09-26 02:39:31.501+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 261 bytes out of 261 available in buffer
>2012-09-26 02:39:31.501+0000: 27597: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x914e10
>2012-09-26 02:39:31.549+0000: 27597: debug : qemuDomainObjEndJob:936 : Stopping job: modify (async=none)
>2012-09-26 02:39:31.550+0000: 27597: debug : qemuDriverCloseCallbackRunAll:744 : conn=0x7ffcec0089d0
>2012-09-26 02:39:34.150+0000: 27511: debug : qemuDomainObjBeginJobInternal:807 : Starting job: modify (async=none)
>2012-09-26 02:39:34.151+0000: 27511: debug : qemuProcessStart:3358 : Beginning VM startup process
>2012-09-26 02:39:34.151+0000: 27511: debug : qemuProcessStart:3370 : Setting current domain def as transient
>2012-09-26 02:39:34.151+0000: 27511: debug : qemuProcessStart:3396 : Preparing host devices
>2012-09-26 02:39:34.151+0000: 27511: debug : qemuProcessStart:3400 : Preparing chr devices
>2012-09-26 02:39:34.151+0000: 27511: debug : qemuProcessStart:3409 : Generating domain security label (if required)
>2012-09-26 02:39:34.153+0000: 27511: debug : qemuProcessStart:3418 : Ensuring no historical cgroup is lying around
>2012-09-26 02:39:34.153+0000: 27511: debug : qemuProcessStart:3491 : Creating domain log file
>2012-09-26 02:39:34.153+0000: 27511: debug : qemuProcessStart:3496 : Checking for KVM availability
>2012-09-26 02:39:34.153+0000: 27511: debug : qemuProcessStart:3506 : Determining emulator version
>2012-09-26 02:39:34.164+0000: 27511: debug : qemuCapsParseHelpStr:1445 : Version 0.12.1, cooked version 12001, flags 0x00010000000e5c000109fc6cf7effd6e
>2012-09-26 02:39:34.164+0000: 27511: debug : qemuCapsParseHelpStr:1451 : qemu-kvm version 0.12.1 detected
>2012-09-26 02:39:34.254+0000: 27511: debug : qemuProcessStart:3518 : Checking for CDROM and floppy presence
>2012-09-26 02:39:34.254+0000: 27511: debug : qemuProcessStart:3542 : Setting up domain cgroup (if required)
>2012-09-26 02:39:34.256+0000: 27511: debug : qemuSetupDiskPathAllow:70 : Process path /var/lib/libvirt/images/demo.img for disk
>2012-09-26 02:39:34.256+0000: 27511: debug : qemuSetupDiskPathAllow:70 : Process path /var/lib/libvirt/images/disk.img for disk
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuProcessStart:3551 : Preparing monitor state
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuProcessStart:3587 : Assigning domain PCI addresses
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:5.0
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.1 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.2 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.3 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.4 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.5 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.6 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:5.7 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:3.0
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.1 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.2 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.3 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.4 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.5 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.6 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:3.7 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:2.0
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.1 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.2 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.3 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.4 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.5 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.6 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:2.7 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:1.2
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:1.1
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1028 : Remembering PCI addr 0:0:4.0
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.1 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.2 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.3 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.4 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.5 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.6 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuCollectPCIAddress:1054 : Remembering PCI addr 0:0:4.7 (multifunction=off for function 0)
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.0
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.1
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.2
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.3
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.4
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.5
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.6
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:0.7
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.0
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.3
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.4
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.5
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.6
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:1.7
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuProcessStart:3592 : Building emulator command line
>2012-09-26 02:39:34.257+0000: 27511: debug : qemuBuildCommandLine:4470 : conn=0x7ffce8000ae0 driver=0x7ffcec027a70 def=0x7ffcec18cc70 mon=0x7ffce400bd60 json=1 caps=0x7ffce400f4b0 migrateFrom=(null) migrateFD=-1 snapshot=(nil) vmop=0
>2012-09-26 02:39:34.270+0000: 27511: debug : qemuProcessStart:3637 : Clear emulator capabilities: 1
>2012-09-26 02:39:34.275+0000: 27511: debug : qemuProcessStart:3684 : Writing early domain status to disk
>2012-09-26 02:39:34.367+0000: 27511: debug : qemuProcessStart:3689 : Waiting for handshake from child
>2012-09-26 02:39:34.368+0000: 27511: debug : qemuProcessStart:3694 : Setting domain security labels
>2012-09-26 02:39:34.368+0000: 27511: debug : qemuProcessStart:3723 : Labelling done, completing handshake to child
>2012-09-26 02:39:34.369+0000: 27511: debug : qemuProcessStart:3727 : Handshake complete, child running
>2012-09-26 02:39:34.369+0000: 27511: debug : qemuProcessStart:3738 : Waiting for monitor to show up
>2012-09-26 02:39:34.569+0000: 27511: debug : qemuProcessWaitForMonitor:1613 : Connect monitor to 0x7ffcec188660 'demo1'
>2012-09-26 02:39:34.576+0000: 27511: debug : qemuMonitorOpenInternal:757 : QEMU_MONITOR_NEW: mon=0x7ffce400ddd0 refs=2 fd=27
>2012-09-26 02:39:34.576+0000: 27511: debug : qemuMonitorSetCapabilities:1133 : mon=0x7ffce400ddd0
>2012-09-26 02:39:34.576+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"qmp_capabilities","id":"libvirt-1"}' for write with FD -1
>2012-09-26 02:39:34.576+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"qmp_capabilities","id":"libvirt-1"}
> fd=-1
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}
> len=125
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 125 bytes out of 125 available in buffer
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"qmp_capabilities","id":"libvirt-1"}
> len=49 ret=49 errno=11
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": {}, "id": "libvirt-1"}
> len=35
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {}, "id": "libvirt-1"}]
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": {}, "id": "libvirt-1"}
>2012-09-26 02:39:34.576+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 35 bytes out of 35 available in buffer
>2012-09-26 02:39:34.576+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x916da0
>2012-09-26 02:39:34.576+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-commands","id":"libvirt-2"}' for write with FD -1
>2012-09-26 02:39:34.577+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"query-commands","id":"libvirt-2"}
> fd=-1
>2012-09-26 02:39:34.577+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"query-commands","id":"libvirt-2"}
> len=47 ret=47 errno=11
>2012-09-26 02:39:34.579+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, len=1023
>2012-09-26 02:39:34.579+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 0 bytes out of 1023 available in buffer
>2012-09-26 02:39:34.579+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, {"name": "block-job-cancel"}, {"name": "query-version"}, {"name": "query-commands"}, {"name": "query-chardev"}, {"name": "query-block"}, {"name": "query-blockstats"}, {"name": "query-cpus"}, {"name": "query-kvm"}, {"name": "query-status"}, {"name": "query-mice"}, {"name": "query-vnc"}, {"name": "query-spice"}, {"name": "query-name"}, {"name": "query-uuid"}, {"name": "query-migrate"}, {"name": "query-balloon"}, {"name": "query-block-jobs"}], "id": "libvirt-2"}
> len=1489
>2012-09-26 02:39:34.579+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, {"name": "block-job-cancel"}, {"name": "query-version"}, {"name": "query-commands"}, {"name": "query-chardev"}, {"name": "query-block"}, {"name": "query-blockstats"}, {"name": "query-cpus"}, {"name": "query-kvm"}, {"name": "query-status"}, {"name": "query-mice"}, {"name": "query-vnc"}, {"name": "query-spice"}, {"name": "query-name"}, {"name": "query-uuid"}, {"name": "query-migrate"}, {"name": "query-balloon"}, {"name": "query-block-jobs"}], "id": "libvirt-2"}]
>2012-09-26 02:39:34.579+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "screendump"}, {"name": "__com.redhat_qxl_screendump"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"}, {"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name": "__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "block-job-set-speed"}, {"name": "block-job-cancel"}, {"name": "query-version"}, {"name": "query-commands"}, {"name": "query-chardev"}, {"name": "query-block"}, {"name": "query-blockstats"}, {"name": "query-cpus"}, {"name": "query-kvm"}, {"name": "query-status"}, {"name": "query-mice"}, {"name": "query-vnc"}, {"name": "query-spice"}, {"name": "query-name"}, {"name": "query-uuid"}, {"name": "query-migrate"}, {"name": "query-balloon"}, {"name": "query-block-jobs"}], "id": "libvirt-2"}
>2012-09-26 02:39:34.579+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 1489 bytes out of 1489 available in buffer
>2012-09-26 02:39:34.579+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x917140
>2012-09-26 02:39:34.580+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-events","id":"libvirt-3"}' for write with FD -1
>2012-09-26 02:39:34.580+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"query-events","id":"libvirt-3"}
> fd=-1
>2012-09-26 02:39:34.580+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"query-events","id":"libvirt-3"}
> len=45 ret=45 errno=11
>2012-09-26 02:39:34.580+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"id": "libvirt-3", "error": {"class": "CommandNotFound", "desc": "The command query-events has not been found", "data": {"name": "query-events"}}}
> len=149
>2012-09-26 02:39:34.580+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"id": "libvirt-3", "error": {"class": "CommandNotFound", "desc": "The command query-events has not been found", "data": {"name": "query-events"}}}]
>2012-09-26 02:39:34.580+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"id": "libvirt-3", "error": {"class": "CommandNotFound", "desc": "The command query-events has not been found", "data": {"name": "query-events"}}}
>2012-09-26 02:39:34.580+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 149 bytes out of 149 available in buffer
>2012-09-26 02:39:34.580+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x90c520
>2012-09-26 02:39:34.580+0000: 27511: debug : qemuMonitorGetPtyPaths:2493 : mon=0x7ffce400ddd0
>2012-09-26 02:39:34.580+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-chardev","id":"libvirt-4"}' for write with FD -1
>2012-09-26 02:39:34.580+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"query-chardev","id":"libvirt-4"}
> fd=-1
>2012-09-26 02:39:34.580+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"query-chardev","id":"libvirt-4"}
> len=46 ret=46 errno=11
>2012-09-26 02:39:34.581+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": [{"filename": "unix:/var/lib/libvirt/qemu/demo1.monitor,server", "label": "charmonitor"}, {"filename": "pty:/dev/pts/18", "label": "charserial0"}], "id": "libvirt-4"}
> len=179
>2012-09-26 02:39:34.581+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": [{"filename": "unix:/var/lib/libvirt/qemu/demo1.monitor,server", "label": "charmonitor"}, {"filename": "pty:/dev/pts/18", "label": "charserial0"}], "id": "libvirt-4"}]
>2012-09-26 02:39:34.581+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": [{"filename": "unix:/var/lib/libvirt/qemu/demo1.monitor,server", "label": "charmonitor"}, {"filename": "pty:/dev/pts/18", "label": "charserial0"}], "id": "libvirt-4"}
>2012-09-26 02:39:34.581+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 179 bytes out of 179 available in buffer
>2012-09-26 02:39:34.581+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x90d5b0
>2012-09-26 02:39:34.581+0000: 27511: debug : qemuProcessWaitForMonitor:1631 : qemuMonitorGetPtyPaths returned 0
>2012-09-26 02:39:34.581+0000: 27511: debug : qemuProcessStart:3750 : Detecting VCPU PIDs
>2012-09-26 02:39:34.581+0000: 27511: debug : qemuMonitorGetCPUInfo:1267 : mon=0x7ffce400ddd0
>2012-09-26 02:39:34.581+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"query-cpus","id":"libvirt-5"}' for write with FD -1
>2012-09-26 02:39:34.581+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"query-cpus","id":"libvirt-5"}
> fd=-1
>2012-09-26 02:39:34.581+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"query-cpus","id":"libvirt-5"}
> len=43 ret=43 errno=11
>2012-09-26 02:39:34.582+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": [{"current": true, "CPU": 0, "pc": 4294967280, "halted": false, "thread_id": 27631}], "id": "libvirt-5"}
> len=117
>2012-09-26 02:39:34.582+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": [{"current": true, "CPU": 0, "pc": 4294967280, "halted": false, "thread_id": 27631}], "id": "libvirt-5"}]
>2012-09-26 02:39:34.582+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": [{"current": true, "CPU": 0, "pc": 4294967280, "halted": false, "thread_id": 27631}], "id": "libvirt-5"}
>2012-09-26 02:39:34.582+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 117 bytes out of 117 available in buffer
>2012-09-26 02:39:34.582+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x90d760
>2012-09-26 02:39:34.582+0000: 27511: debug : qemuProcessStart:3754 : Setting cgroup for each VCPU (if required)
>2012-09-26 02:39:34.604+0000: 27511: debug : qemuProcessStart:3758 : Setting cgroup for emulator (if required)
>2012-09-26 02:39:34.652+0000: 27511: warning : virCgroupMoveTask:885 : no vm cgroup in controller 3
>2012-09-26 02:39:34.652+0000: 27511: warning : virCgroupMoveTask:885 : no vm cgroup in controller 4
>2012-09-26 02:39:34.652+0000: 27511: warning : virCgroupMoveTask:885 : no vm cgroup in controller 6
>2012-09-26 02:39:34.652+0000: 27511: debug : qemuProcessStart:3762 : Setting VCPU affinities
>2012-09-26 02:39:34.653+0000: 27511: debug : qemuProcessStart:3766 : Setting affinity of emulator threads
>2012-09-26 02:39:34.653+0000: 27511: debug : qemuProcessStart:3770 : Setting any required VM passwords
>2012-09-26 02:39:34.653+0000: 27511: debug : qemuProcessStart:3785 : Setting network link states
>2012-09-26 02:39:34.653+0000: 27511: debug : qemuProcessStart:3798 : Setting initial memory amount
>2012-09-26 02:39:34.653+0000: 27511: debug : qemuMonitorSetBalloon:1670 : mon=0x7ffce400ddd0 newmem=1048576
>2012-09-26 02:39:34.653+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"balloon","arguments":{"value":1073741824},"id":"libvirt-6"}' for write with FD -1
>2012-09-26 02:39:34.653+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"balloon","arguments":{"value":1073741824},"id":"libvirt-6"}
> fd=-1
>2012-09-26 02:39:34.653+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"balloon","arguments":{"value":1073741824},"id":"libvirt-6"}
> len=73 ret=73 errno=11
>2012-09-26 02:39:34.654+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": {}, "id": "libvirt-6"}
> len=35
>2012-09-26 02:39:34.654+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {}, "id": "libvirt-6"}]
>2012-09-26 02:39:34.654+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": {}, "id": "libvirt-6"}
>2012-09-26 02:39:34.654+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 35 bytes out of 35 available in buffer
>2012-09-26 02:39:34.654+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x913510
>2012-09-26 02:39:34.654+0000: 27511: debug : qemuProcessStart:3814 : Starting domain CPUs
>2012-09-26 02:39:34.654+0000: 27511: debug : qemuProcessStartCPUs:2678 : Using lock state '(null)'
>2012-09-26 02:39:34.654+0000: 27511: debug : qemuMonitorStartCPUs:1167 : mon=0x7ffce400ddd0
>2012-09-26 02:39:34.654+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"cont","id":"libvirt-7"}' for write with FD -1
>2012-09-26 02:39:34.654+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"cont","id":"libvirt-7"}
> fd=-1
>2012-09-26 02:39:34.654+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"cont","id":"libvirt-7"}
> len=37 ret=37 errno=11
>2012-09-26 02:39:34.655+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"timestamp": {"seconds": 1348627174, "microseconds": 654933}, "event": "RESUME"}
>{"return": {}, "id": "libvirt-7"}
> len=118
>2012-09-26 02:39:34.655+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"timestamp": {"seconds": 1348627174, "microseconds": 654933}, "event": "RESUME"}]
>2012-09-26 02:39:34.655+0000: 27510: debug : qemuMonitorJSONIOProcessLine:161 : QEMU_MONITOR_RECV_EVENT: mon=0x7ffce400ddd0 event={"timestamp": {"seconds": 1348627174, "microseconds": 654933}, "event": "RESUME"}
>2012-09-26 02:39:34.655+0000: 27510: debug : qemuMonitorJSONIOProcessEvent:118 : mon=0x7ffce400ddd0 obj=0x913070
>2012-09-26 02:39:34.655+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {}, "id": "libvirt-7"}]
>2012-09-26 02:39:34.655+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": {}, "id": "libvirt-7"}
>2012-09-26 02:39:34.655+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 118 bytes out of 118 available in buffer
>2012-09-26 02:39:34.655+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x933210
>2012-09-26 02:39:34.655+0000: 27511: debug : qemuProcessStart:3835 : Writing domain status to disk
>2012-09-26 02:39:34.718+0000: 27511: debug : qemuDomainObjEndJob:936 : Stopping job: modify (async=none)
>2012-09-26 02:39:34.720+0000: 27510: debug : qemuDriverCloseCallbackRunAll:744 : conn=0x7ffce8000ae0
>2012-09-26 02:39:49.483+0000: 27514: debug : qemuDomainObjBeginJobInternal:807 : Starting job: modify (async=none)
>2012-09-26 02:39:49.483+0000: 27514: debug : qemuMonitorDelDevice:2597 : mon=0x7ffce400ddd0 devalias=virtio-disk0
>2012-09-26 02:39:49.483+0000: 27514: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"device_del","arguments":{"id":"virtio-disk0"},"id":"libvirt-8"}' for write with FD -1
>2012-09-26 02:39:49.483+0000: 27514: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"device_del","arguments":{"id":"virtio-disk0"},"id":"libvirt-8"}
> fd=-1
>2012-09-26 02:39:49.484+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"device_del","arguments":{"id":"virtio-disk0"},"id":"libvirt-8"}
> len=77 ret=77 errno=11
>2012-09-26 02:39:49.484+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": {}, "id": "libvirt-8"}
> len=35
>2012-09-26 02:39:49.484+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {}, "id": "libvirt-8"}]
>2012-09-26 02:39:49.484+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": {}, "id": "libvirt-8"}
>2012-09-26 02:39:49.484+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 35 bytes out of 35 available in buffer
>2012-09-26 02:39:49.484+0000: 27514: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x9125b0
>2012-09-26 02:39:49.484+0000: 27514: debug : qemuMonitorDriveDel:2578 : mon=0x7ffce400ddd0 drivestr=drive-virtio-disk0
>2012-09-26 02:39:49.484+0000: 27514: debug : qemuMonitorJSONDriveDel:3200 : JSONDriveDel drivestr=drive-virtio-disk0
>2012-09-26 02:39:49.484+0000: 27514: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"__com.redhat_drive_del","arguments":{"id":"drive-virtio-disk0"},"id":"libvirt-9"}' for write with FD -1
>2012-09-26 02:39:49.484+0000: 27514: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"__com.redhat_drive_del","arguments":{"id":"drive-virtio-disk0"},"id":"libvirt-9"}
> fd=-1
>2012-09-26 02:39:49.484+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"__com.redhat_drive_del","arguments":{"id":"drive-virtio-disk0"},"id":"libvirt-9"}
> len=95 ret=95 errno=11
>2012-09-26 02:39:49.485+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": {}, "id": "libvirt-9"}
> len=35
>2012-09-26 02:39:49.485+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {}, "id": "libvirt-9"}]
>2012-09-26 02:39:49.485+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": {}, "id": "libvirt-9"}
>2012-09-26 02:39:49.485+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 35 bytes out of 35 available in buffer
>2012-09-26 02:39:49.485+0000: 27514: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x912140
>2012-09-26 02:39:49.577+0000: 27514: debug : qemuTeardownDiskPathDeny:114 : Process path /var/lib/libvirt/images/disk.img for disk
>2012-09-26 02:39:49.619+0000: 27514: debug : qemuDomainObjEndJob:936 : Stopping job: modify (async=none)
>2012-09-26 02:39:49.621+0000: 27510: debug : qemuDriverCloseCallbackRunAll:744 : conn=0x7ffce400e030
>2012-09-26 02:40:02.809+0000: 27511: debug : qemuDomainObjBeginJobInternal:807 : Starting job: modify (async=none)
>2012-09-26 02:40:02.810+0000: 27511: debug : qemuSetupDiskPathAllow:70 : Process path /var/lib/libvirt/images/disk.img for disk
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressGetNextSlot:1371 : PCI addr 0:0:2.0 already in use
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressGetNextSlot:1371 : PCI addr 0:0:3.0 already in use
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressGetNextSlot:1371 : PCI addr 0:0:4.0 already in use
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressGetNextSlot:1376 : Found free PCI addr 0:0:5.0
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.0
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.1
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.2
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.3
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.4
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.5
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.6
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:5.7
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuMonitorAddDrive:2654 : mon=0x7ffce400ddd0 drive=file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/disk.img","id":"drive-virtio-disk1","format":"raw","cache":"none"},"id":"libvirt-10"}' for write with FD -1
>2012-09-26 02:40:02.812+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/disk.img","id":"drive-virtio-disk1","format":"raw","cache":"none"},"id":"libvirt-10"}
> fd=-1
>2012-09-26 02:40:02.817+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/disk.img","id":"drive-virtio-disk1","format":"raw","cache":"none"},"id":"libvirt-10"}
> len=168 ret=168 errno=11
>2012-09-26 02:40:02.819+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"return": {}, "id": "libvirt-10"}
> len=36
>2012-09-26 02:40:02.819+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"return": {}, "id": "libvirt-10"}]
>2012-09-26 02:40:02.819+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"return": {}, "id": "libvirt-10"}
>2012-09-26 02:40:02.819+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 36 bytes out of 36 available in buffer
>2012-09-26 02:40:02.819+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x9117d0
>2012-09-26 02:40:02.819+0000: 27511: debug : qemuMonitorAddDeviceWithFd:2620 : mon=0x7ffce400ddd0 device=virtio-blk-pci,scsi=off,bus=pci.0,addr=0x5,drive=drive-virtio-disk1,id=virtio-disk1 fd=-1 fdname=(null)
>2012-09-26 02:40:02.819+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"device_add","arguments":{"driver":"virtio-blk-pci","scsi":"off","bus":"pci.0","addr":"0x5","drive":"drive-virtio-disk1","id":"virtio-disk1"},"id":"libvirt-11"}' for write with FD -1
>2012-09-26 02:40:02.819+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"device_add","arguments":{"driver":"virtio-blk-pci","scsi":"off","bus":"pci.0","addr":"0x5","drive":"drive-virtio-disk1","id":"virtio-disk1"},"id":"libvirt-11"}
> fd=-1
>2012-09-26 02:40:02.819+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"device_add","arguments":{"driver":"virtio-blk-pci","scsi":"off","bus":"pci.0","addr":"0x5","drive":"drive-virtio-disk1","id":"virtio-disk1"},"id":"libvirt-11"}
> len=173 ret=173 errno=11
>2012-09-26 02:40:02.820+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"id": "libvirt-11", "error": {"class": "DeviceInitFailed", "desc": "Device 'virtio-blk-pci' could not be initialized", "data": {"device": "virtio-blk-pci"}}}
> len=160
>2012-09-26 02:40:02.820+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"id": "libvirt-11", "error": {"class": "DeviceInitFailed", "desc": "Device 'virtio-blk-pci' could not be initialized", "data": {"device": "virtio-blk-pci"}}}]
>2012-09-26 02:40:02.820+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"id": "libvirt-11", "error": {"class": "DeviceInitFailed", "desc": "Device 'virtio-blk-pci' could not be initialized", "data": {"device": "virtio-blk-pci"}}}
>2012-09-26 02:40:02.820+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 160 bytes out of 160 available in buffer
>2012-09-26 02:40:02.820+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x911360
>2012-09-26 02:40:02.820+0000: 27511: debug : qemuMonitorJSONCheckError:338 : unable to execute QEMU command {"execute":"device_add","arguments":{"driver":"virtio-blk-pci","scsi":"off","bus":"pci.0","addr":"0x5","drive":"drive-virtio-disk1","id":"virtio-disk1"},"id":"libvirt-11"}: {"id":"libvirt-11","error":{"class":"DeviceInitFailed","desc":"Device 'virtio-blk-pci' could not be initialized","data":{"device":"virtio-blk-pci"}}}
>2012-09-26 02:40:02.820+0000: 27511: error : qemuMonitorJSONCheckError:349 : internal error unable to execute QEMU command 'device_add': Device 'virtio-blk-pci' could not be initialized
>2012-09-26 02:40:02.820+0000: 27511: debug : qemuMonitorDriveDel:2578 : mon=0x7ffce400ddd0 drivestr=file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none
>2012-09-26 02:40:02.820+0000: 27511: debug : qemuMonitorJSONDriveDel:3200 : JSONDriveDel drivestr=file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none
>2012-09-26 02:40:02.820+0000: 27511: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"__com.redhat_drive_del","arguments":{"id":"file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none"},"id":"libvirt-12"}' for write with FD -1
>2012-09-26 02:40:02.820+0000: 27511: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"__com.redhat_drive_del","arguments":{"id":"file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none"},"id":"libvirt-12"}
> fd=-1
>2012-09-26 02:40:02.821+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"__com.redhat_drive_del","arguments":{"id":"file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none"},"id":"libvirt-12"}
> len=167 ret=167 errno=11
>2012-09-26 02:40:02.821+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"id": "libvirt-12", "error": {"class": "DeviceNotFound", "desc": "Device 'file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none' not found", "data": {"device": "file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none"}}}
> len=293
>2012-09-26 02:40:02.821+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"id": "libvirt-12", "error": {"class": "DeviceNotFound", "desc": "Device 'file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none' not found", "data": {"device": "file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none"}}}]
>2012-09-26 02:40:02.821+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"id": "libvirt-12", "error": {"class": "DeviceNotFound", "desc": "Device 'file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none' not found", "data": {"device": "file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none"}}}
>2012-09-26 02:40:02.822+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 293 bytes out of 293 available in buffer
>2012-09-26 02:40:02.822+0000: 27511: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x9109d0
>2012-09-26 02:40:02.912+0000: 27511: debug : qemuTeardownDiskPathDeny:114 : Process path /var/lib/libvirt/images/disk.img for disk
>2012-09-26 02:40:02.912+0000: 27511: debug : qemuDomainObjEndJob:936 : Stopping job: modify (async=none)
>2012-09-26 02:40:02.917+0000: 27510: debug : qemuDriverCloseCallbackRunAll:744 : conn=0x7ffce8046b90
>2012-09-26 02:40:03.821+0000: 27513: debug : qemuDomainObjBeginJobInternal:807 : Starting job: modify (async=none)
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuSetupDiskPathAllow:70 : Process path /var/lib/libvirt/images/disk.img for disk
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressGetNextSlot:1376 : Found free PCI addr 0:0:6.0
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.0
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.1
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.2
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.3
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.4
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.5
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.6
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuDomainPCIAddressReserveAddr:1201 : Reserving PCI addr 0:0:6.7
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuMonitorAddDrive:2654 : mon=0x7ffce400ddd0 drive=file=/var/lib/libvirt/images/disk.img,if=none,id=drive-virtio-disk1,format=raw,cache=none
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuMonitorJSONCommandWithFd:259 : Send command '{"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/disk.img","id":"drive-virtio-disk1","format":"raw","cache":"none"},"id":"libvirt-13"}' for write with FD -1
>2012-09-26 02:40:03.822+0000: 27513: debug : qemuMonitorSend:894 : QEMU_MONITOR_SEND_MSG: mon=0x7ffce400ddd0 msg={"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/disk.img","id":"drive-virtio-disk1","format":"raw","cache":"none"},"id":"libvirt-13"}
> fd=-1
>2012-09-26 02:40:03.822+0000: 27510: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffce400ddd0 buf={"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/disk.img","id":"drive-virtio-disk1","format":"raw","cache":"none"},"id":"libvirt-13"}
> len=168 ret=168 errno=11
>2012-09-26 02:40:03.823+0000: 27510: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffce400ddd0 buf={"id": "libvirt-13", "error": {"class": "DuplicateId", "desc": "Duplicate ID 'drive-virtio-disk1' for drive", "data": {"object": "drive", "id": "drive-virtio-disk1"}}}
> len=169
>2012-09-26 02:40:03.823+0000: 27510: debug : qemuMonitorJSONIOProcessLine:146 : Line [{"id": "libvirt-13", "error": {"class": "DuplicateId", "desc": "Duplicate ID 'drive-virtio-disk1' for drive", "data": {"object": "drive", "id": "drive-virtio-disk1"}}}]
>2012-09-26 02:40:03.824+0000: 27510: debug : qemuMonitorJSONIOProcessLine:166 : QEMU_MONITOR_RECV_REPLY: mon=0x7ffce400ddd0 reply={"id": "libvirt-13", "error": {"class": "DuplicateId", "desc": "Duplicate ID 'drive-virtio-disk1' for drive", "data": {"object": "drive", "id": "drive-virtio-disk1"}}}
>2012-09-26 02:40:03.824+0000: 27510: debug : qemuMonitorJSONIOProcess:217 : Total used 169 bytes out of 169 available in buffer
>2012-09-26 02:40:03.824+0000: 27513: debug : qemuMonitorJSONCommandWithFd:264 : Receive command reply ret=0 rxObject=0x90fb40
>2012-09-26 02:40:03.824+0000: 27513: debug : qemuMonitorJSONCheckError:338 : unable to execute QEMU command {"execute":"__com.redhat_drive_add","arguments":{"file":"/var/lib/libvirt/images/disk.img","id":"drive-virtio-disk1","format":"raw","cache":"none"},"id":"libvirt-13"}: {"id":"libvirt-13","error":{"class":"DuplicateId","desc":"Duplicate ID 'drive-virtio-disk1' for drive","data":{"object":"drive","id":"drive-virtio-disk1"}}}
>2012-09-26 02:40:03.824+0000: 27513: error : qemuMonitorJSONCheckError:349 : internal error unable to execute QEMU command '__com.redhat_drive_add': Duplicate ID 'drive-virtio-disk1' for drive
>2012-09-26 02:40:03.913+0000: 27513: debug : qemuTeardownDiskPathDeny:114 : Process path /var/lib/libvirt/images/disk.img for disk
>2012-09-26 02:40:03.913+0000: 27513: debug : qemuDomainObjEndJob:936 : Stopping job: modify (async=none)
>2012-09-26 02:40:03.915+0000: 27510: debug : qemuDriverCloseCallbackRunAll:744 : conn=0x7ffce0000ae0

Actions: View

Attachments on bug 844408: 601283 | 601910 | 617362