On 2015-05-07 16:41, Daan Hoogland wrote:
But if your patient I'll get there.
I'm here to see it through to the end ;) The good news is Remi's note
worked. I've included output below.
On 2015-05-07 16:42, Remi Bergsma wrote:
Hi Mike,
Can you check if the agent has debug logging enabled in log4j.xml? If
not, this enables it:
sed -i 's/INFO/DEBUG/g' /etc/cloudstack/agent/log4j-cloud.xml
Restart agent, then try again and we should see more logs.
I've included logs on both the "source agent" which is currently running
the VM and the "destination agent" which is the target of the migrate.
=========================
========== Source Agent
=========================
2015-05-08 09:58:13,943 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Request:Seq 1-5821465468329787407: { Cmd
, MgmtId: 114374076129940, via: 1, Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.MigrateCommand":{"vmName":"r-93-VM","destIp":"172.16.16.31","hostGuid":"9a421209-fb8b-30ad-8304-95a4e33f3286-LibvirtComputingResource","isWindows":false,"vmTO":{"id":93,"name":"r-93-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"Debian
GNU/Linux
7(64-bit)","platformEmulator":"Other","bootArgs":"","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"2b74e551cba07566","params":{},"uuid":"5269e919-564a-4986-92c1-07464e99e3ce","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"c1b45654-5e74-420e-bf91-5beb745546f8","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"d5174632-721e-39ed-b93b-462539f63c77","id":1,"poolType":"NetworkFilesystem","host":"172.16.16.25","path":"/srv/cloudstack/primary/0001","port":2049,"url":"NetworkFilesystem://172.16.16.25/srv/cloudstack/primary/0001/?ROLE=Primary&STOREUUID=d5174632-721e-39ed-b93b-462539f63c77"}},"name":"ROOT-93","size":2621440000,"path":"c1b45654-5e74-420e-bf91-5beb745546f8","volumeId":132,"vmName":"r-93-VM","accountId":2,"format":"QCOW2","id":132,"deviceId":0,"cacheMode":"NONE","hypervisorType":"KVM"}},"diskSeq":0,"path":"c1b45654-5e74-420e-bf91-5beb745546f8","ty
pe":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"172.16.16.25","volumeSize":"2621440000"}}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"nicUuid":"3ae999b5-9d59-431a-a41b-7dbeb90c5509","uuid":"a011df28-a322-4d94-bf31-1f4fbb7a869b","ip":"172.16.18.1","netmask":"255.255.255.0","mac":"02:00:6b:5b:00:03","dns1":"172.16.17.2","dns2":"","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1209","isolationUri":"vlan://1209","isSecurityGroupEnabled":false,"name":"cloudbr1"},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"nicUuid":"cd17fc0c-164e-4fe8-acc0-36a13f37f5aa","uuid":"0e669946-5f4d-4c51-9b2e-564edc1dc06a","ip":"169.254.3.203","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:03:cb","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"nicUuid":"9bc37269-68d5-40b8-ac08-4b60ccab5d0f","uuid":"80c92696-16cb-427e-855a-a2ac01c34ebc","i
p":"172.16.17.202","netmask":"255.255.255.0","gateway":"172.16.17.2","mac":"06:13:ca:00:00:36","dns1":"172.16.17.2","dns2":"","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://untagged","isolationUri":"vlan://untagged","isSecurityGroupEnabled":false,"name":"cloudbr0"}]},"executeInSequence":false,"wait":0}}]
}
2015-05-08 09:58:13,943 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Processing command:
com.cloud.agent.api.MigrateCommand
2015-05-08 09:58:13,975 INFO [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Live migration of instance r-93-VM
initiated
2015-05-08 09:58:14,277 INFO [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Migration thread for r-93-VM is done
2015-05-08 09:58:14,278 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Failed to execute while migrating domain:
org.libvirt.LibvirtException: Cannot get interface MTU on
'brbond0-1209': No such device
2015-05-08 09:58:14,290 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Seq 1-5821465468329787407: { Ans: ,
MgmtId: 114374076129940, via: 1, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.MigrateAnswer":{"result":false,"details":"org.libvirt.LibvirtException:
Cannot get interface MTU on 'brbond0-1209': No such device","wait":0}}]
}
=========================
======= Destination Agent
=========================
2015-05-08 09:58:13,766 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Request:Seq 18-630503947831869460: { Cmd
, MgmtId: 114374076129940, via: 18, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.PrepareForMigrationCommand":{"vm":{"id":93,"name":"r-93-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"Debian
GNU/Linux
7(64-bit)","platformEmulator":"Other","bootArgs":"","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"2b74e551cba07566","params":{},"uuid":"5269e919-564a-4986-92c1-07464e99e3ce","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"c1b45654-5e74-420e-bf91-5beb745546f8","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"d5174632-721e-39ed-b93b-462539f63c77","id":1,"poolType":"NetworkFilesystem","host":"172.16.16.25","path":"/srv/cloudstack/primary/0001","port":2049,"url":"NetworkFilesystem://172.16.16.25/srv/cloudstack/primary/0001/?ROLE=Primary&STOREUUID=d5174632-721e-39ed-b93b-462539f63c77"}},"name":"ROOT-93","size":2621440000,"path":"c1b45654-5e74-420e-bf91-5beb745546f8","volumeId":132,"vmName":"r-93-VM","accountId":2,"format":"QCOW2","id":132,"deviceId":0,"cacheMode":"NONE","hypervisorType":"KVM"}},"diskSeq":0,"path":"c1b45654-5e74-420e-bf91-5beb745546f8","ty
pe":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"172.16.16.25","volumeSize":"2621440000"}}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"nicUuid":"3ae999b5-9d59-431a-a41b-7dbeb90c5509","uuid":"a011df28-a322-4d94-bf31-1f4fbb7a869b","ip":"172.16.18.1","netmask":"255.255.255.0","mac":"02:00:6b:5b:00:03","dns1":"172.16.17.2","dns2":"","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1209","isolationUri":"vlan://1209","isSecurityGroupEnabled":false,"name":"cloudbr1"},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"nicUuid":"cd17fc0c-164e-4fe8-acc0-36a13f37f5aa","uuid":"0e669946-5f4d-4c51-9b2e-564edc1dc06a","ip":"169.254.3.203","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:03:cb","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"nicUuid":"9bc37269-68d5-40b8-ac08-4b60ccab5d0f","uuid":"80c92696-16cb-427e-855a-a2ac01c34ebc","i
p":"172.16.17.202","netmask":"255.255.255.0","gateway":"172.16.17.2","mac":"06:13:ca:00:00:36","dns1":"172.16.17.2","dns2":"","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://untagged","isolationUri":"vlan://untagged","isSecurityGroupEnabled":false,"name":"cloudbr0"}]},"wait":0}}]
}
2015-05-08 09:58:13,766 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Processing command:
com.cloud.agent.api.PrepareForMigrationCommand
2015-05-08 09:58:13,766 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Preparing host for migrating
com.cloud.agent.api.to.VirtualMachineTO@2a15bf12
2015-05-08 09:58:13,769 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-5:null) can't find connection: KVM, for vm:
r-93-VM, continue
2015-05-08 09:58:13,772 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-5:null) can't find connection: LXC, for vm:
r-93-VM, continue
2015-05-08 09:58:13,772 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-5:null) can't find which hypervisor the vm used ,
then use the default hypervisor
2015-05-08 09:58:13,774 DEBUG [kvm.resource.BridgeVifDriver]
(agentRequest-Handler-5:null) nic=[Nic:Guest-172.16.18.1-vlan://1209]
2015-05-08 09:58:13,774 DEBUG [kvm.resource.BridgeVifDriver]
(agentRequest-Handler-5:null) creating a vNet dev and bridge for guest
traffic per traffic label cloudbr1
2015-05-08 09:58:13,774 DEBUG [kvm.resource.BridgeVifDriver]
(agentRequest-Handler-5:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/vnet/modifyvlan.sh -v
1209 -p eth0 -b breth0-1209 -o add
2015-05-08 09:58:13,794 DEBUG [kvm.resource.BridgeVifDriver]
(agentRequest-Handler-5:null) Execution is successful.
2015-05-08 09:58:13,795 DEBUG [kvm.resource.BridgeVifDriver]
(agentRequest-Handler-5:null) Set name-type for VLAN subsystem. Should
be visible in /proc/net/vlan/config
2015-05-08 09:58:13,796 DEBUG [kvm.resource.BridgeVifDriver]
(agentRequest-Handler-5:null) nic=[Nic:Control-169.254.3.203-null]
2015-05-08 09:58:13,796 DEBUG [utils.script.Script]
(agentRequest-Handler-5:null) Executing: /bin/bash -c ip route | grep
169.254.0.0/16
2015-05-08 09:58:13,802 DEBUG [utils.script.Script]
(agentRequest-Handler-5:null) Execution is successful.
2015-05-08 09:58:13,803 DEBUG [kvm.resource.BridgeVifDriver]
(agentRequest-Handler-5:null)
nic=[Nic:Public-172.16.17.202-vlan://untagged]
2015-05-08 09:58:13,878 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Seq 18-630503947831869460: { Ans: ,
MgmtId: 114374076129940, via: 18, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.PrepareForMigrationAnswer":{"result":true,"wait":0}}]
}
2015-05-08 09:58:14,305 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Request:Seq 18-630503947831869461: { Cmd
, MgmtId: 114374076129940, via: 18, Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"r-93-VM","wait":0}}]
}
2015-05-08 09:58:14,306 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Processing command:
com.cloud.agent.api.StopCommand
2015-05-08 09:58:14,309 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find connection: KVM, for vm:
r-93-VM, continue
2015-05-08 09:58:14,312 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find connection: LXC, for vm:
r-93-VM, continue
2015-05-08 09:58:14,312 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find which hypervisor the vm used ,
then use the default hypervisor
2015-05-08 09:58:14,316 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-93-VM'
2015-05-08 09:58:14,318 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-93-VM'
2015-05-08 09:58:14,322 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-93-VM'
2015-05-08 09:58:14,322 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-93-VM
2015-05-08 09:58:14,485 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Execution is successful.
2015-05-08 09:58:14,487 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Try to stop the vm at first
2015-05-08 09:58:14,490 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) VM r-93-VM doesn't exist, no need to stop
it
2015-05-08 09:58:14,491 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Seq 18-630503947831869461: { Ans: ,
MgmtId: 114374076129940, via: 18, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2015-05-08 09:58:56,341 DEBUG [kvm.resource.KVMHAMonitor]
(Thread-6:null) Found NFS storage pool
d5174632-721e-39ed-b93b-462539f63c77 in libvirt, continuing
