Bug 740355

Summary: virsh migrate fails with "Undefined Error"
Product: Red Hat Enterprise Linux 6 Reporter: Ian Allison <iana>
Component: libvirtAssignee: Dave Allan <dallan>
Status: CLOSED WORKSFORME QA Contact: Virtualization Bugs <virt-bugs>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.1CC: acathrow, dallan, jyang, mzhan, rwu, weizhan
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-03-28 17:40:16 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Description Ian Allison 2011-09-21 18:31:34 UTC
Description of problem:
Virsh migrate betweeen two hosts with NFS shared storage fails with an Undefined Error.

Version-Release number of selected component (if applicable):
$ rpm -q libvirt
libvirt-0.8.7-18.el6_1.1.x86_64

How reproducible:
Always

Steps to Reproduce:
1. Guest running on 1st host
  root@host1$ virsh list
   Id Name                 State
   ----------------------------------
   15 TracSvn              running

2. Start migrate to host2
  root@host1$ virsh migrate TracSvn qemu+ssh://host1.<DOMAIN_NAME>/system

  
Actual results:
error: internal error unable to execute QEMU command 'migrate': An undefined error has ocurred


Expected results:
Host migrates to host2.

Additional info:
SELINUX has been set to permissive on both hosts and iptables have been flushed (except for the rules loaded by libvirtd).

I've tried to gather more debugging information by adding the following lines to libvirtd.conf on the hosts

HOST1
  log_filters="1:qemu"
  log_outputs="1:file:/var/log/libvirt/client.log"

HOST2
  log_filters="1:qemu"
  log_outputs="1:file:/var/log/libvirt/daemon.log"

Here are the results


^^^^^^ BEGIN client.log ^^^^^^
0:57:55.951: 32741: info : libvirt version: 0.8.7, package: 18.el6_1.1 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2011-08-08-05:23:02, x86-012.build.bos.redhat.com)
10:57:55.951: 32741: error : virSysinfoRead:106 : internal error Failed to find path for dmidecode binary
10:57:55.962: 32741: info : qemudLoadDriverConfig:312 : Configured cgroup controller 'cpu'
10:57:55.962: 32741: info : qemudLoadDriverConfig:312 : Configured cgroup controller 'memory'
10:57:55.962: 32741: info : qemudLoadDriverConfig:312 : Configured cgroup controller 'devices'
10:57:55.962: 32741: info : qemudLoadDriverConfig:312 : Configured cgroup controller 'blkio'
10:57:55.963: 32741: info : qemudSecurityInit:1429 : Initialized security driver selinux
10:57:55.992: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:55.992: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:56.227: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:56.227: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:56.479: 32741: debug : qemuCreateCapabilities:1478 : Initialized caps for security driver "selinux" with DOI "0"
10:57:56.490: 32741: debug : qemuReconnectDomain:1324 : Reconnect monitor to 0x1ffbfa0 'Ash'
10:57:56.498: 32741: debug : qemuMonitorOpen:692 : New mon 0x21523b0 fd =19 watch=5
10:57:56.498: 32741: debug : qemuMonitorSetCapabilities:933 : mon=0x21523b0
10:57:56.498: 32741: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"qmp_capabilities"}' for write with FD -1
10:57:56.499: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
10:57:56.499: 32742: debug : qemuMonitorJSONIOProcessLine:130 : Got QMP capabilities data
10:57:56.499: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 125 bytes out of 125 available in buffer
10:57:56.499: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:57:56.499: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:57:56.499: 32741: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:57:56.512: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:56.512: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:56.697: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:5
10:57:56.698: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:3
10:57:56.698: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:4
10:57:56.698: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:2
10:57:56.698: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:1
10:57:56.698: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:6
10:57:56.698: 32741: debug : qemuDomainPCIAddressReserveAddr:751 : Reserving PCI addr 0:0:0
10:57:56.699: 32741: debug : qemuReconnectDomain:1324 : Reconnect monitor to 0x1ff7940 'cap'
10:57:56.707: 32741: debug : qemuMonitorOpen:692 : New mon 0x2151030 fd =20 watch=6
10:57:56.707: 32741: debug : qemuMonitorSetCapabilities:933 : mon=0x2151030
10:57:56.707: 32741: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"qmp_capabilities"}' for write with FD -1
10:57:56.707: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
10:57:56.707: 32742: debug : qemuMonitorJSONIOProcessLine:130 : Got QMP capabilities data
10:57:56.707: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 125 bytes out of 125 available in buffer
10:57:56.707: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:57:56.707: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:57:56.707: 32741: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:57:56.720: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:56.720: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:56.958: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:5
10:57:56.958: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:3
10:57:56.958: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:4
10:57:56.958: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:2
10:57:56.958: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:1
10:57:56.958: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:6
10:57:56.958: 32741: debug : qemuDomainPCIAddressReserveAddr:751 : Reserving PCI addr 0:0:0
10:57:56.959: 32741: debug : qemuReconnectDomain:1324 : Reconnect monitor to 0x20d9b10 'TracSvn'
10:57:56.964: 32741: debug : qemuMonitorOpen:692 : New mon 0x2153e10 fd =21 watch=7
10:57:56.964: 32741: debug : qemuMonitorSetCapabilities:933 : mon=0x2153e10
10:57:56.964: 32741: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"qmp_capabilities"}' for write with FD -1
10:57:56.964: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
10:57:56.965: 32742: debug : qemuMonitorJSONIOProcessLine:130 : Got QMP capabilities data
10:57:56.965: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 125 bytes out of 125 available in buffer
10:57:56.965: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:57:56.965: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:57:56.965: 32741: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:57:56.978: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:56.978: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:57.205: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:5
10:57:57.205: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:3
10:57:57.205: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:4
10:57:57.205: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:2
10:57:57.205: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:1
10:57:57.205: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:6
10:57:57.205: 32741: debug : qemuDomainPCIAddressReserveAddr:751 : Reserving PCI addr 0:0:0
10:57:57.206: 32741: debug : qemuReconnectDomain:1324 : Reconnect monitor to 0x20d8e00 'forestat'
10:57:57.212: 32741: debug : qemuMonitorOpen:692 : New mon 0x2154500 fd =22 watch=8
10:57:57.213: 32741: debug : qemuMonitorSetCapabilities:933 : mon=0x2154500
10:57:57.213: 32741: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"qmp_capabilities"}' for write with FD -1
10:57:57.213: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
10:57:57.213: 32742: debug : qemuMonitorJSONIOProcessLine:130 : Got QMP capabilities data
10:57:57.213: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 125 bytes out of 125 available in buffer
10:57:57.213: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:57:57.213: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:57:57.213: 32741: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:57:57.225: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:57.225: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:57.475: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:5
10:57:57.475: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:3
10:57:57.475: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:4
10:57:57.475: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:2
10:57:57.475: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:1
10:57:57.475: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:6
10:57:57.475: 32741: debug : qemuDomainPCIAddressReserveAddr:751 : Reserving PCI addr 0:0:0
10:57:57.476: 32741: debug : qemuReconnectDomain:1324 : Reconnect monitor to 0x207ecb0 'Pine'
10:57:57.483: 32741: debug : qemuMonitorOpen:692 : New mon 0x2154c10 fd =23 watch=9
10:57:57.484: 32741: debug : qemuMonitorSetCapabilities:933 : mon=0x2154c10
10:57:57.484: 32741: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"qmp_capabilities"}' for write with FD -1
10:57:57.484: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
10:57:57.484: 32742: debug : qemuMonitorJSONIOProcessLine:130 : Got QMP capabilities data
10:57:57.484: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 125 bytes out of 125 available in buffer
10:57:57.484: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:57:57.484: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:57:57.484: 32741: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:57:57.496: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:57.496: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:57.704: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:5
10:57:57.704: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:3
10:57:57.704: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:4
10:57:57.704: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:2
10:57:57.704: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:1
10:57:57.704: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:6
10:57:57.704: 32741: debug : qemuDomainPCIAddressReserveAddr:751 : Reserving PCI addr 0:0:0
10:57:57.705: 32741: debug : qemuReconnectDomain:1324 : Reconnect monitor to 0x1fface0 'Rcloud'
10:57:57.712: 32741: debug : qemuMonitorOpen:692 : New mon 0x2152e20 fd =24 watch=10
10:57:57.712: 32741: debug : qemuMonitorSetCapabilities:933 : mon=0x2152e20
10:57:57.712: 32741: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"qmp_capabilities"}' for write with FD -1
10:57:57.712: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
10:57:57.712: 32742: debug : qemuMonitorJSONIOProcessLine:130 : Got QMP capabilities data
10:57:57.712: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 125 bytes out of 125 available in buffer
10:57:57.712: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:57:57.712: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:57:57.712: 32741: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:57:57.726: 32741: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:57:57.726: 32741: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:57:57.945: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:5
10:57:57.945: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:3
10:57:57.945: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:4
10:57:57.945: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:2
10:57:57.945: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:1
10:57:57.945: 32741: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:6
10:57:57.945: 32741: debug : qemuDomainPCIAddressReserveAddr:751 : Reserving PCI addr 0:0:0
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain Ash in /var/lib/libvirt/qemu/snapshot/Ash
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain cap in /var/lib/libvirt/qemu/snapshot/cap
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain Community in /var/lib/libvirt/qemu/snapshot/Community
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain SG-rhel6 in /var/lib/libvirt/qemu/snapshot/SG-rhel6
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain TracSvn in /var/lib/libvirt/qemu/snapshot/TracSvn
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain forestat in /var/lib/libvirt/qemu/snapshot/forestat
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain Pine in /var/lib/libvirt/qemu/snapshot/Pine
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain Rcloud in /var/lib/libvirt/qemu/snapshot/Rcloud
10:57:57.960: 32741: info : qemuDomainSnapshotLoad:1513 : Scanning for snapshots for domain SG-Xu1104 in /var/lib/libvirt/qemu/snapshot/SG-Xu1104
10:57:58.784: 32743: debug : qemudGetProcessInfo:3852 : Got status for 4791/0 user=226254 sys=332677 cpu=9
10:57:58.784: 32743: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x2153e10
10:57:58.784: 32743: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:57:58.785: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:57:58.785: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:57:58.785: 32743: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:57:58.786: 32744: debug : qemudGetProcessInfo:3852 : Got status for 4983/0 user=123902 sys=309265 cpu=26
10:57:58.786: 32744: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x2151030
10:57:58.786: 32744: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:57:58.787: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:57:58.787: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:57:58.787: 32744: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:57:58.788: 32746: debug : qemudGetProcessInfo:3852 : Got status for 5184/0 user=113600 sys=302039 cpu=35
10:57:58.788: 32746: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x2152e20
10:57:58.788: 32746: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:57:58.788: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:57:58.788: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:57:58.788: 32746: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:57:58.789: 32747: debug : qemudGetProcessInfo:3852 : Got status for 5397/0 user=129334 sys=336472 cpu=31
10:57:58.789: 32747: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x2154500
10:57:58.789: 32747: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:57:58.790: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:57:58.790: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:57:58.790: 32747: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:57:58.791: 32745: debug : qemudGetProcessInfo:3852 : Got status for 5658/0 user=29572 sys=21594 cpu=15
10:57:58.791: 32745: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x21523b0
10:57:58.791: 32745: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:57:58.791: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:57:58.791: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:57:58.791: 32745: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:57:58.792: 32743: debug : qemudGetProcessInfo:3852 : Got status for 5838/0 user=50597 sys=88252 cpu=24
10:57:58.792: 32743: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x2154c10
10:57:58.792: 32743: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:57:58.793: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:57:58.793: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:57:58.793: 32743: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:58:07.503: 32745: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x2153e10
10:58:07.503: 32745: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:58:07.504: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:58:07.504: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:58:07.504: 32745: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:58:07.505: 32746: debug : qemudGetProcessInfo:3852 : Got status for 4791/0 user=226269 sys=332713 cpu=6
10:58:07.505: 32746: debug : qemuMonitorGetBalloonInfo:1032 : mon=0x2153e10
10:58:07.505: 32746: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-balloon"}' for write with FD -1
10:58:07.505: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {"actual": 4294967296}}]
10:58:07.505: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 36 bytes out of 36 available in buffer
10:58:07.505: 32746: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 34 bytes '{"return": {"actual": 4294967296}}'
10:58:07.929: 32743: debug : qemuMonitorStopCPUs:974 : mon=0x2153e10
10:58:07.929: 32743: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"stop"}' for write with FD -1
10:58:07.934: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"timestamp": {"seconds": 1316627887, "microseconds": 934671}, "event": "STOP"}]
10:58:07.934: 32742: debug : qemuMonitorJSONIOProcessEvent:87 : mon=0x2153e10 obj=0x7ff218001340
10:58:07.934: 32742: debug : qemuMonitorJSONIOProcessEvent:100 : handle STOP handler=0x475020 data=(nil)
10:58:07.934: 32742: debug : qemuMonitorEmitStop:840 : mon=0x2153e10
10:58:07.934: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:58:07.934: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 97 bytes out of 97 available in buffer
10:58:07.934: 32743: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:58:07.935: 32743: debug : doNativeMigrate:8974 : Cookie='<qemu-migration id='2'>
  <name>TracSvn</name>
  <uuid>2d197930-e6ef-a5b0-f44e-3cb83d87cf03</uuid>
  <hostname>120kvm2.<MYDOMAINHERE></hostname>
  <graphics type='vnc' port='5900' listen='0.0.0.0'/>
</qemu-migration>
' len=215'
10:58:07.935: 32743: debug : qemuDomainObjMigrationXMLParseStr:504 : xml=<qemu-migration id='2'>
  <name>TracSvn</name>
  <uuid>2d197930-e6ef-a5b0-f44e-3cb83d87cf03</uuid>
  <hostname>120kvm2.<MYDOMAINHERE></hostname>
  <graphics type='vnc' port='5900' listen='0.0.0.0'/>
</qemu-migration>

10:58:07.935: 32743: debug : qemuMonitorMigrateToHost:1367 : mon=0x2153e10 hostname=120kvm2.stat.ubc.ca port=49153 flags=1
10:58:07.935: 32743: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"migrate","arguments":{"detach":true,"blk":false,"inc":false,"uri":"tcp:120kvm2.stat.ubc.ca:49153"}}' for write with FD -1
10:58:07.936: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"error": {"class": "UndefinedError", "desc": "An undefined error has ocurred", "data": {}}}]
10:58:07.936: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 94 bytes out of 94 available in buffer
10:58:07.936: 32743: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 92 bytes '{"error": {"class": "UndefinedError", "desc": "An undefined error has ocurred", "data": {}}}'
10:58:07.936: 32743: debug : qemuMonitorJSONCheckError:306 : unable to execute QEMU command {"execute":"migrate","arguments":{"detach":true,"blk":false,"inc":false,"uri":"tcp:120kvm2.stat.ubc.ca:49153"}}: {"error":{"class":"UndefinedError","desc":"An undefined error has ocurred","data":{}}}
10:58:07.936: 32743: error : qemuMonitorJSONCheckError:317 : internal error unable to execute QEMU command 'migrate': An undefined error has ocurred
10:58:07.936: 32743: debug : qemuMonitorStartCPUs:954 : mon=0x2153e10
10:58:07.936: 32743: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"cont"}' for write with FD -1
10:58:07.939: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"timestamp": {"seconds": 1316627887, "microseconds": 939662}, "event": "RESUME"}]
10:58:07.939: 32742: debug : qemuMonitorJSONIOProcessEvent:87 : mon=0x2153e10 obj=0x7ff218001340
10:58:07.939: 32742: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:58:07.939: 32742: debug : qemuMonitorJSONIOProcess:189 : Total used 99 bytes out of 99 available in buffer
10:58:07.939: 32743: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'

^^^^^^ END client.log ^^^^^^




^^^^^^ BEGIN daemon.log ^^^^^^
10:58:07.445: 3100: debug : qemudDomainMigratePrepare2:8853 : Generated uri_out=tcp:120kvm2.stat.ubc.ca:49153
10:58:07.445: 3100: debug : qemudStartVMDaemon:3095 : Beginning VM startup process
10:58:07.445: 3100: debug : qemudStartVMDaemon:3107 : Setting current domain def as transient
10:58:07.445: 3100: debug : qemudStartVMDaemon:3114 : Preparing host devices
10:58:07.445: 3100: debug : qemudStartVMDaemon:3118 : Preparing chr devices
10:58:07.445: 3100: debug : qemudStartVMDaemon:3127 : Generating domain security label (if required)
10:58:07.456: 3100: debug : qemudStartVMDaemon:3137 : Generating setting domain security labels (if required)
10:58:07.456: 3100: info : qemuSecurityDACSetOwnership:40 : Setting DAC user and group on '/nfs/kvm_ug_a/HD/TracSvn.qcow2' to '107:107'
10:58:07.468: 3100: debug : qemudStartVMDaemon:3167 : Ensuring no historical cgroup is lying around
10:58:07.470: 3100: debug : qemudStartVMDaemon:3213 : Creating domain log file
10:58:07.470: 3100: debug : qemudStartVMDaemon:3217 : Determining emulator version
10:58:07.492: 3100: debug : qemuCapsParseHelpStr:1034 : Version 0.12.1, cooked version 12001, flags 0x8109fe6cd6effd6e
10:58:07.492: 3100: debug : qemuCapsParseHelpStr:1038 : qemu-kvm version 0.12.1 detected
10:58:07.610: 3100: debug : qemudStartVMDaemon:3223 : Setting up domain cgroup (if required)
10:58:07.611: 3100: debug : qemuSetupDiskPathAllow:67 : Process path /nfs/kvm_ug_a/HD/TracSvn.qcow2 for disk
10:58:07.613: 3100: debug : qemudStartVMDaemon:3232 : Preparing monitor state
10:58:07.614: 3100: debug : qemudStartVMDaemon:3267 : Assigning domain PCI addresses
10:58:07.614: 3100: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:5
10:58:07.614: 3100: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:3
10:58:07.614: 3100: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:4
10:58:07.614: 3100: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:2
10:58:07.614: 3100: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:1
10:58:07.614: 3100: debug : qemuCollectPCIAddress:708 : Remembering PCI addr 0:0:6
10:58:07.614: 3100: debug : qemuDomainPCIAddressReserveAddr:751 : Reserving PCI addr 0:0:0
10:58:07.614: 3100: debug : qemudStartVMDaemon:3286 : Building emulator command line
10:58:07.646: 3100: debug : qemudStartVMDaemon:3332 : Clear emulator capabilities: 1
10:58:07.646: 3100: warning : qemudStartVMDaemon:3336 : Executing /usr/libexec/qemu-kvm
10:58:07.652: 3100: warning : qemudStartVMDaemon:3346 : Executing done /usr/libexec/qemu-kvm
10:58:07.652: 3100: debug : qemudStartVMDaemon:3385 : Waiting for monitor to show up
10:58:07.852: 3100: debug : qemudWaitForMonitor:2278 : Connect monitor to 0x7f381c003730 'TracSvn'
10:58:07.862: 3100: debug : qemuMonitorOpen:692 : New mon 0x7f381c000b10 fd =23 watch=10
10:58:07.862: 3100: debug : qemuMonitorSetCapabilities:933 : mon=0x7f381c000b10
10:58:07.862: 3100: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"qmp_capabilities"}' for write with FD -1
10:58:07.863: 3099: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"QMP": {"version": {"qemu": {"micro": 1, "minor": 12, "major": 0}, "package": "(qemu-kvm-0.12.1.2)"}, "capabilities": []}}]
10:58:07.863: 3099: debug : qemuMonitorJSONIOProcessLine:130 : Got QMP capabilities data
10:58:07.863: 3099: debug : qemuMonitorJSONIOProcess:189 : Total used 125 bytes out of 125 available in buffer
10:58:07.863: 3099: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:58:07.863: 3099: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:58:07.863: 3100: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:58:07.863: 3100: debug : qemuMonitorGetPtyPaths:1801 : mon=0x7f381c000b10
10:58:07.863: 3100: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-chardev"}' for write with FD -1
10:58:07.864: 3099: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": [{"filename": "unix:/var/lib/libvirt/qemu/TracSvn.monitor,server", "label": "charmonitor"}, {"filename": "pty:/dev/pts/1", "label": "charserial0"}]}]
10:58:07.864: 3099: debug : qemuMonitorJSONIOProcess:189 : Total used 161 bytes out of 161 available in buffer
10:58:07.864: 3100: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 159 bytes '{"return": [{"filename": "unix:/var/lib/libvirt/qemu/TracSvn.monitor,server", "label": "charmonitor"}, {"filename": "pty:/dev/pts/1", "label": "charserial0"}]}'
10:58:07.864: 3100: debug : qemudWaitForMonitor:2298 : qemuMonitorGetPtyPaths returned 0
10:58:07.864: 3100: debug : qemudStartVMDaemon:3389 : Detecting VCPU PIDs
10:58:07.864: 3100: debug : qemuMonitorGetCPUInfo:1013 : mon=0x7f381c000b10
10:58:07.864: 3100: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"query-cpus"}' for write with FD -1
10:58:07.864: 3099: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": [{"current": true, "CPU": 0, "pc": 4294967280, "halted": false, "thread_id": 3281}, {"current": false, "CPU": 1, "pc": 4294967280, "halted": true, "thread_id": 3282}]}]
10:58:07.864: 3099: debug : qemuMonitorJSONIOProcess:189 : Total used 180 bytes out of 180 available in buffer
10:58:07.864: 3100: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 178 bytes '{"return": [{"current": true, "CPU": 0, "pc": 4294967280, "halted": false, "thread_id": 3281}, {"current": false, "CPU": 1, "pc": 4294967280, "halted": true, "thread_id": 3282}]}'
10:58:07.864: 3100: debug : qemudStartVMDaemon:3393 : Setting any required VM passwords
10:58:07.864: 3100: debug : qemudStartVMDaemon:3405 : Setting initial memory amount
10:58:07.864: 3100: debug : qemuMonitorSetBalloon:1167 : mon=0x7f381c000b10 newmem=4194304
10:58:07.864: 3100: debug : qemuMonitorJSONCommandWithFd:218 : Send command '{"execute":"balloon","arguments":{"value":4294967296}}' for write with FD -1
10:58:07.865: 3099: debug : qemuMonitorJSONIOProcessLine:116 : Line [{"return": {}}]
10:58:07.865: 3099: debug : qemuMonitorJSONIOProcess:189 : Total used 16 bytes out of 16 available in buffer
10:58:07.865: 3100: debug : qemuMonitorJSONCommandWithFd:223 : Receive command reply ret=0 errno=0 14 bytes '{"return": {}}'
10:58:07.865: 3100: debug : qemudStartVMDaemon:3426 : Writing domain status to disk
10:58:07.865: 3100: debug : qemudDomainMigratePrepare2:8909 : Try Encode cookie 0x7f383530aaf0 0x7f383530aafc
10:58:07.880: 3104: debug : qemudShutdownVMDaemon:3460 : Shutting down VM 'TracSvn' pid=3261 migrated=1
10:58:07.880: 3104: debug : qemuMonitorClose:715 : mon=0x7f381c000b10
10:58:07.880: 3104: debug : qemuSecurityDACRestoreSecurityAllLabel:426 : Restoring security label on TracSvn migrated=1
10:58:07.880: 3099: debug : qemuMonitorFree:207 : mon=0x7f381c000b10
10:58:07.881: 3104: debug : qemuSecurityDACRestoreSecurityImageLabelInt:161 : Skipping image label restore on /nfs/kvm_ug_a/HD/TracSvn.qcow2 because FS is shared
10:58:07.882: 3104: error : virCgroupRemoveRecursively:679 : Unable to remove /cgroup/cpu/libvirt/qemu/TracSvn/ (16)
10:58:07.882: 3104: error : virCgroupRemoveRecursively:679 : Unable to remove /cgroup/cpuacct/libvirt/qemu/TracSvn/ (16)
10:58:07.882: 3104: error : virCgroupRemoveRecursively:679 : Unable to remove /cgroup/cpuset/libvirt/qemu/TracSvn/ (16)
10:58:07.882: 3104: error : virCgroupRemoveRecursively:679 : Unable to remove /cgroup/memory/libvirt/qemu/TracSvn/ (16)
10:58:07.882: 3104: error : virCgroupRemoveRecursively:679 : Unable to remove /cgroup/devices/libvirt/qemu/TracSvn/ (16)
10:58:07.882: 3104: error : virCgroupRemoveRecursively:679 : Unable to remove /cgroup/freezer/libvirt/qemu/TracSvn/ (16)
10:58:07.882: 3104: error : virCgroupRemoveRecursively:679 : Unable to remove /cgroup/blkio/libvirt/qemu/TracSvn/ (16)

^^^^^^ END daemon.log ^^^^^^

Comment 2 Dave Allan 2011-09-21 20:37:05 UTC
There are a variety of reasons that you might see this error, and qemu unfortunately doesn't provide detail on which one might be causing your problem.  Generally the most common two causes are:

1) a firewall is blocking the migration.  I'm guessing you know that since you mentioned that you've already flushed the iptables rules except for the ones added by libvirt, but unless you need the ones added by libvirt, flush all of them and stop iptables.  I wonder if there's a default rule in there that's rejecting the traffic.

2) DNS resolution is broken.  Migration is sensitive to DNS errors.  Confirm that both forward and reverse DNS is configured correctly throughout your network.  In particular, confirm that both source and destination can resolve and reverse resolve each other.  

If you have a support contract with Red Hat, I recommend that you open a support ticket.

Comment 3 Ian Allison 2011-09-21 20:50:10 UTC
Hi Dave,

(In reply to comment #2)
> 1) a firewall is blocking the migration.  I'm guessing you know that since you
> mentioned that you've already flushed the iptables rules except for the ones
> added by libvirt, but unless you need the ones added by libvirt, flush all of
> them and stop iptables.  I wonder if there's a default rule in there that's
> rejecting the traffic.
> 
> 2) DNS resolution is broken.  Migration is sensitive to DNS errors.  Confirm
> that both forward and reverse DNS is configured correctly throughout your
> network.  In particular, confirm that both source and destination can resolve
> and reverse resolve each other.  

I've removed all firewall rules and checked forward and reverse DNS entries are resolving correctly on both hosts, but I still get the same problem.

> If you have a support contract with Red Hat, I recommend that you open a
> support ticket.

I'm further down the foodchain than that. I need to convince one of the higher-ups to do it but I'm not holding my breath.

Thanks,
      Ian.

Comment 4 Dave Allan 2011-09-21 21:46:30 UTC
Can you provide the details of the NFS mount used on both hosts?  Also, (I realize a longshot here) can you try with a test host on iSCSI?

Comment 5 Osier Yang 2011-09-22 01:07:49 UTC
This should be duplicated with https://bugzilla.redhat.com/show_bug.cgi?id=615941, and the problem is fixed after we changed to use qemu fd: protocol, see https://bugzilla.redhat.com/show_bug.cgi?id=720269.

So, both these 2 bugs might be able to closed now.

Comment 6 Dave Allan 2011-09-22 01:13:57 UTC
Osier, the fix you're referring to would give him a better error and probably tell him what the problem is, but it's not going to make his problem go away.  IIUC, he's filing this bug against the fact that his migration is failing, not about the error message.

Comment 7 Ian Allison 2011-09-22 16:59:20 UTC
Hi Dave, The NFS mount is a version 3 mount coming from a NetApp

rim:/vol/kvm/kvm_ug_a	/nfs/kvm_ug_a	nfs	vers=3,defaults,_netdev 0 0

We haven't had much luck with our iSCSI setup so I can't get any debugging information from there at the moment. It sounds like name resolution is the most likely culprit so I'll keep looking there for any problems.

Comment 10 Dave Allan 2011-11-17 23:11:22 UTC
(In reply to comment #7)
> We haven't had much luck with our iSCSI setup so I can't get any debugging
> information from there at the moment. It sounds like name resolution is the
> most likely culprit so I'll keep looking there for any problems.

Ian, did you ever find root cause?

Comment 11 Ian Allison 2011-11-17 23:35:59 UTC
(In reply to comment #10)
> (In reply to comment #7)
> > We haven't had much luck with our iSCSI setup so I can't get any debugging
> > information from there at the moment. It sounds like name resolution is the
> > most likely culprit so I'll keep looking there for any problems.
> 
> Ian, did you ever find root cause?

Nope, in our current setup migration is rare enough that it hasn't been a major issue, whenever there has been an kernel, kvm or libvirt update I try again but I haven't looked at in a while. If I get time this weekend I might give it a go.

Comment 12 Dave Allan 2011-11-18 00:49:19 UTC
Before you do that, confirm the forward and reverse DNS information on both the source and destination hosts.  It might be a little less work that actually trying a migration.  Personally I like the 'host' command for that, but choose your poison!  :)

Comment 13 Dave Allan 2012-01-04 20:10:49 UTC
Ian, any word?

Comment 14 Ian Allison 2012-01-09 23:03:49 UTC
(In reply to comment #13)
> Ian, any word?

Sorry for the delay, just back from a holiday. The machines in question are still running 6.1 we are in the process of updating the guests but there are a lot of them and we dont expect to be updating the hosts till next week. As soon as we are done I will try again, I noticed that 6.2 brings a bunch of VM updates.

Comment 15 Ian Allison 2012-01-09 23:26:54 UTC
I should have mentioned that I've checked the forward and reverse entries for the source and destination machines from both the source and destination (all combinations). Everything looks fine. The forward mapping is just an A record and the reverse mapping picks out the correct hostname.domainname in all cases.

Comment 16 Dave Allan 2012-03-28 15:19:13 UTC
Any new information?  BTW, are you able to migrate on any hosts?  I'd really like to see the output from a 6.2 host as the error reporting has been greatly improved.

Comment 17 Ian Allison 2012-03-28 15:54:14 UTC
We updated everything to 6.2 and the problem is gone! thanks so much. Please let me know if you need any more information - otherwise feel free to close the bug.

-Thanks

Comment 18 Dave Allan 2012-03-28 17:40:16 UTC
Good to know; I'll do that.  Thanks.