Good day Cloudstack Devs,
I've run across a real head scratcher. I have two VMs, (initially 3 VMs, but
more on that later) on a single host, that I cannot live migrate to any other
host in the same cluster. We discovered this after attempting to roll out
patches going from CentOS 7.2 to CentOS 7.4. Initially, we thought it had
something to do with the new version of libvirtd or qemu-kvm on the other hosts
in the cluster preventing these VMs from migrating, but we are able to live
migrate other VMs to and from this host without issue. We can even create new
VMs on this specific host and live migrate them after creation with no issue.
We've put the migration source agent, migration destination agent and the
management server in debug and don't seem to get anything useful other than
"Unsupported command". Luckily, we did have one VM that was shutdown and
restarted, this is the 3rd VM mentioned above. Since that VM has been
restarted, it has no issues live migrating to any other host in the cluster.
I'm at a loss as to what to try next and I'm hoping that someone out there
might have had a similar issue and could shed some light on what to do.
Obviously, I can contact the customer and have them shutdown their VMs, but
that will potentially just delay this problem to be solved another day. Even
if shutting down the VMs is ultimately the solution, I'd still like to
understand what happened to cause this issue in the first place with the hopes
of preventing it in the future.
Here's some information about my setup:
Cloudstack 4.8 Advanced Networking
CentOS 7.2 and 7.4 Hosts
Ceph RBD Primary Storage
NFS Secondary Storage
Instance in Question for Debug: i-532-1392-NSVLTN
I have attached relevant debug logs to this email if anyone wishes to take a
look. I think the most interesting error message that I have received is the
following:
468390:2018-01-27 08:59:35,172 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Seq 22-942378222027276319: Received: { Ans: , MgmtId:
14038012703634, via: 22(csh02c01z01.nsvltn.ena.net), Ver: v1, Flags: 110, {
UnsupportedAnswer } }
468391:2018-01-27 08:59:35,172 WARN [c.c.a.m.AgentManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Unsupported Command: Unsupported command issued:
com.cloud.agent.api.PrepareForMigrationCommand. Are you sure you got the right
type of server?
468392:2018-01-27 08:59:35,179 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Invocation exception, caused by:
com.cloud.exception.AgentUnavailableException: Resource [Host:22] is
unreachable: Host 22: Unable to prepare for migration due to Unsupported
command issued: com.cloud.agent.api.PrepareForMigrationCommand. Are you sure
you got the right type of server?
468393:2018-01-27 08:59:35,179 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Rethrow exception
com.cloud.exception.AgentUnavailableException: Resource [Host:22] is
unreachable: Host 22: Unable to prepare for migration due to Unsupported
command issued: com.cloud.agent.api.PrepareForMigrationCommand. Are you sure
you got the right type of server?
I've tracked this "Unsupported command" down in the CS 4.8 code to
cloudstack/api/src/com/cloud/agent/api/Answer.java which is the generic answer
class. I believe where the error is really being spawned from is
cloudstack/engine/orchestration/src/com/cloud/vm/VirtualMachineManagerImpl.java.
Specifically:
Answer pfma = null;
try {
pfma = _agentMgr.send(dstHostId, pfmc);
if (pfma == null || !pfma.getResult()) {
final String details = pfma != null ? pfma.getDetails() : "null
answer returned";
final String msg = "Unable to prepare for migration due to " +
details;
pfma = null;
throw new AgentUnavailableException(msg, dstHostId);
}
The pfma returned must be in error or is never returned and therefore still
null. That answer appears that it should be coming from the destination agent,
but for the life of me I can't figure out what the root cause of this error is
beyond, "Unsupported command issued". What command is unsupported? My guess
is that it could be something wrong with the dxml that is generated and passed
to the destination host, but I have as yet been unable to catch that dxml in
debug.
Any help or guidance is greatly appreciated.
Thanks,
David Mabry
Management Server Debug
=================================
468377:2018-01-27 08:59:35,101 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ce324459) (logid:943aafdc) Execute sync-queue
item: SyncQueueItemVO {id:69592, queueId: 65982, contentType: AsyncJob,
contentId: 181802, lastProcessMsid: 14038012703634, lastprocessNumber: 48,
lastProcessTime: Sat Jan 27 08:59:35 CST 2018, created: Sat Jan 27 08:59:34 CST
2018}
468378:2018-01-27 08:59:35,101 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ce324459) (logid:943aafdc) Schedule queued
job-181802
468379:2018-01-27 08:59:35,103 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:b6fc9593) Add
job-181802 into job monitoring
468380:2018-01-27 08:59:35,108 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362)
Executing AsyncJobVO {id:181802, userId: 2, accountId: 2, instanceType: null,
instanceId: null, cmd: com.cloud.vm.VmWorkMigrate, cmdInfo:
rO0ABXNyABpjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZRdxQXtPtzYqAgAGSgAJc3JjSG9zdElkTAAJY2x1c3RlcklkdAAQTGphdmEvbGFuZy9Mb25nO0wABmhvc3RJZHEAfgABTAAFcG9kSWRxAH4AAUwAB3N0b3JhZ2V0AA9MamF2YS91dGlsL01hcDtMAAZ6b25lSWRxAH4AAXhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAFcHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAADHNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAAAnNxAH4ABwAAAAAAAAAWcQB-AAlwcQB-AAk,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 14038012870814, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Sat Jan 27 08:59:34 CST 2018}
468381:2018-01-27 08:59:35,110 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362) Run
VM work job: com.cloud.vm.VmWorkMigrate for VM 1392, job origin: 181792
468382:2018-01-27 08:59:35,111 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Execute VM work job:
com.cloud.vm.VmWorkMigrate{"zoneId":2,"podId":2,"clusterId":2,"hostId":22,"srcHostId":12,"userId":2,"accountId":2,"vmId":1392,"handlerName":"VirtualMachineManagerImpl"}
468383:2018-01-27 08:59:35,114 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Migrating VM[User|i-532-1392-NSVLTN] to
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(2)-Pod(2)-Cluster(2)-Host(22)-Storage()]
468384:2018-01-27 08:59:35,117 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Service SecurityGroup is not supported in the network id=291
468385:2018-01-27 08:59:35,121 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Service SecurityGroup is not supported in the network id=291
468386:2018-01-27 08:59:35,124 DEBUG [o.a.c.e.o.VolumeOrchestrator]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Preparing 2 volumes for VM[User|i-532-1392-NSVLTN]
468387:2018-01-27 08:59:35,142 DEBUG [c.c.a.m.ClusteredAgentAttache]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Seq 22-942378222027276319: Forwarding Seq
22-942378222027276319: { Cmd , MgmtId: 14038012703634, via:
22(csh02c01z01.nsvltn.ena.net), Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.PrepareForMigrationCommand":{"vm":{"id":1392,"name":"i-532-1392-NSVLTN","type":"User","cpus":2,"minSpeed":2000,"maxSpeed":2000,"minRam":4294967296,"maxRam":4294967296,"arch":"x86_64","os":"Other
PV Virtio-SCSI (64-bit)","platformEmulator":"Other PV Virtio-SCSI
(64-bit)","bootArgs":"","enableHA":true,"limitCpuUse":true,"enableDynamicallyScaleVm":false,"vncPassword":"Nj3rVkFUOcN6PWfrtCIfhg","params":{"memoryOvercommitRatio":"1.0","cpuNumber":"2","cpuSpeed":"2000","keyboard":"us","Message.ReservedCapacityFreed.Flag":"false","cpuOvercommitRatio":"2.0","memory":"4096"},"uuid":"f7dbf00b-2e15-4991-a407-cf27a3d65d1e","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"97e5a299-1efd-40ed-85f4-a5c365a56414","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"10a32867-3386-369e-a391-c8e05e0fa8ed","id":22,"poolType":"RBD","host":"cephmonc01.nsvltn.ena.net","path":"c01z01","port":6789,"url":"RBD://cephmonc01.nsvltn.ena.net/c01z01/?ROLE=Primary&STOREUUID=10a32867-3386-369e-a391-c8e05e0fa8ed"}},"name":"DATA-1392","size":2684354560000,"path":"97e5a299-1efd-40ed-85f4-a5c365a56414","volumeId":22732,"vmName":"i-532-1392-NSVLTN","accountId":532,"format":"RAW","provisioningType":"THIN","id":22732,"deviceId":1,"bytesReadRate":524288000,"bytesWriteRate":524288000,"iopsReadRate":500,"iopsWriteRate":500,"hypervisorType":"KVM"}},"diskSeq":1,"path":"97e5a299-1efd-40ed-85f4-a5c365a56414","type":"DATADISK","_details":{"managed":"false","storagePort":"6789","storageHost":"cephmonc01.nsvltn.ena.net","volumeSize":"2684354560000"}},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"223e08b0-929c-4c47-833d-1f1de48610f3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"10a32867-3386-369e-a391-c8e05e0fa8ed","id":22,"poolType":"RBD","host":"cephmonc01.nsvltn.ena.net","path":"c01z01","port":6789,"url":"RBD://cephmonc01.nsvltn.ena.net/c01z01/?ROLE=Primary&STOREUUID=10a32867-3386-369e-a391-c8e05e0fa8ed"}},"name":"ROOT-1392","size":53687091200,"path":"223e08b0-929c-4c47-833d-1f1de48610f3","volumeId":22742,"vmName":"i-532-1392-NSVLTN","accountId":532,"format":"RAW","provisioningType":"THIN","id":22742,"deviceId":0,"bytesReadRate":524288000,"bytesWriteRate":524288000,"iopsReadRate":500,"iopsWriteRate":500,"hypervisorType":"KVM"}},"diskSeq":0,"path":"223e08b0-929c-4c47-833d-1f1de48610f3","type":"ROOT","_details":{"managed":"false","storagePort":"6789","storageHost":"cephmonc01.nsvltn.ena.net","volumeSize":"53687091200"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":1000,"defaultNic":true,"pxeDisable":false,"nicUuid":"27ae6acc-6de0-47b0-86c2-c0ecbdd91a8a","uuid":"bb6caa9c-5cdf-4556-a22f-9fa8c70c1056","ip":"172.16.64.172","netmask":"255.255.255.0","gateway":"172.16.64.1","mac":"02:00:08:da:00:1d","dns1":"207.191.179.90","broadcastType":"Vxlan","type":"Guest","isSecurityGroupEnabled":false,"name":"bond0.3531"}],"configDriveLabel":"config"},"wait":0}}]
} to 14038008164014
468390:2018-01-27 08:59:35,172 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Seq 22-942378222027276319: Received: { Ans: , MgmtId:
14038012703634, via: 22(csh02c01z01.nsvltn.ena.net), Ver: v1, Flags: 110, {
UnsupportedAnswer } }
468391:2018-01-27 08:59:35,172 WARN [c.c.a.m.AgentManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Unsupported Command: Unsupported command issued:
com.cloud.agent.api.PrepareForMigrationCommand. Are you sure you got the right
type of server?
468392:2018-01-27 08:59:35,179 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Invocation exception, caused by:
com.cloud.exception.AgentUnavailableException: Resource [Host:22] is
unreachable: Host 22: Unable to prepare for migration due to Unsupported
command issued: com.cloud.agent.api.PrepareForMigrationCommand. Are you sure
you got the right type of server?
468393:2018-01-27 08:59:35,179 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802 ctx-8e7f45ad)
(logid:f0888362) Rethrow exception
com.cloud.exception.AgentUnavailableException: Resource [Host:22] is
unreachable: Host 22: Unable to prepare for migration due to Unsupported
command issued: com.cloud.agent.api.PrepareForMigrationCommand. Are you sure
you got the right type of server?
468394:2018-01-27 08:59:35,179 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362) Done
with run of VM work job: com.cloud.vm.VmWorkMigrate for VM 1392, job origin:
181792
468395:2018-01-27 08:59:35,179 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362)
Unable to complete AsyncJobVO {id:181802, userId: 2, accountId: 2,
instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkMigrate, cmdInfo:
rO0ABXNyABpjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZRdxQXtPtzYqAgAGSgAJc3JjSG9zdElkTAAJY2x1c3RlcklkdAAQTGphdmEvbGFuZy9Mb25nO0wABmhvc3RJZHEAfgABTAAFcG9kSWRxAH4AAUwAB3N0b3JhZ2V0AA9MamF2YS91dGlsL01hcDtMAAZ6b25lSWRxAH4AAXhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAFcHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAADHNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAAAnNxAH4ABwAAAAAAAAAWcQB-AAlwcQB-AAk,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 14038012870814, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Sat Jan 27 08:59:34 CST 2018}, job origin:181792
468419:2018-01-27 08:59:35,184 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362)
Complete async job-181802, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyAC1jb20uY2xvdWQuZXhjZXB0aW9uLkFnZW50VW5hdmFpbGFibGVFeGNlcHRpb24AAAAAVk1PdwIAAHhyADBjb20uY2xvdWQuZXhjZXB0aW9uLlJlc291cmNlVW5hdmFpbGFibGVFeGNlcHRpb24AAAAAVk1PfwIAAkoAA19pZEwABl9zY29wZXQAEUxqYXZhL2xhbmcvQ2xhc3M7eHIAImNvbS5jbG91ZC5leGNlcHRpb24uQ2xvdWRFeGNlcHRpb2556I4b8eRExwIAAkwAC2NzRXJyb3JDb2RldAATTGphdmEvbGFuZy9JbnRlZ2VyO0wABmlkTGlzdHQAFUxqYXZhL3V0aWwvQXJyYXlMaXN0O3hyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcHQAzlJlc291cmNlIFtIb3N0OjIyXSBpcyB1bnJlYWNoYWJsZTogSG9zdCAyMjogVW5hYmxlIHRvIHByZXBhcmUgZm9yIG1pZ3JhdGlvbiBkdWUgdG8gVW5zdXBwb3J0ZWQgY29tbWFuZCBpc3N1ZWQ6IGNvbS5jbG91ZC5hZ2VudC5hcGkuUHJlcGFyZUZvck1pZ3JhdGlvbkNvbW1hbmQuICBBcmUgeW91IHN1cmUgeW91IGdvdCB0aGUgcmlnaHQgdHlwZSBvZiBzZXJ2ZXI_dXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAVc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAlMAAhmaWxlTmFtZXEAfgAJTAAKbWV0aG9kTmFtZXEAfgAJeHAAAAemdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AAdtaWdyYXRlc3EAfgAQAAAHYnEAfgAScQB-ABN0ABJvcmNoZXN0cmF0ZU1pZ3JhdGVzcQB-ABAAABIKcQB-ABJxAH4AE3EAfgAWc3EAfgAQ_____3QAJnN1bi5yZWZsZWN0LkdlbmVyYXRlZE1ldGhvZEFjY2Vzc29yNzk3cHQABmludm9rZXNxAH4AEAAAACt0AChzdW4ucmVmbGVjdC5EZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsdAAhRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbC5qYXZhcQB-ABpzcQB-ABAAAAJedAAYamF2YS5sYW5nLnJlZmxlY3QuTWV0aG9kdAALTWV0aG9kLmphdmFxAH4AGnNxAH4AEAAAAGt0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JzcQB-ABAAABKOcQB-ABJxAH4AE3EAfgAkc3EAfgAQAAAAZnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9ic3EAfgAQAAACKnQAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHNxAH4AEAAAADF0AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnNxAH4AEAAAADh0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxzcQB-ABAAAABndABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgA0dAAPY2FsbFdpdGhDb250ZXh0c3EAfgAQAAAANXEAfgA3cQB-ADR0AA5ydW5XaXRoQ29udGV4dHNxAH4AEAAAAC50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AMHEAfgAxc3EAfgAQAAAB9nEAfgArcQB-ACxxAH4AMXNxAH4AEAAAAdd0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4ANXNxAH4AEAAAAQZ0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYXZhcQB-ADFzcQB-ABAAAAR5dAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJzcQB-ABAAAAJndAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgBGcQB-ADFzcQB-ABAAAALpdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ADFzcgAmamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUxpc3T8DyUxteyOEAIAAUwABGxpc3RxAH4AC3hyACxqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlQ29sbGVjdGlvbhlCAIDLXvceAgABTAABY3QAFkxqYXZhL3V0aWwvQ29sbGVjdGlvbjt4cHNyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHEAfgBSeHNyABFqYXZhLmxhbmcuSW50ZWdlchLioKT3gYc4AgABSQAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAABC9c3EAfgBRAAAAAHcEAAAAAHgAAAAAAAAAFnZyABNjb20uY2xvdWQuaG9zdC5Ib3N0AnjOn-BFiMkCAAB4cA
468420:2018-01-27 08:59:35,185 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362)
Publish async job-181802 complete on message bus
468421:2018-01-27 08:59:35,185 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362) Wake
up jobs related to job-181802
468422:2018-01-27 08:59:35,185 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362)
Update db status for job-181802
468424:2018-01-27 08:59:35,186 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362) Wake
up jobs joined with job-181802 and disjoin all subjobs created from job- 181802
468425:2018-01-27 08:59:35,188 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362) Done
executing com.cloud.vm.VmWorkMigrate for job-181802
468426:2018-01-27 08:59:35,188 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-6:ctx-188ea30f job-181792/job-181802) (logid:f0888362)
Remove job-181802 from job monitoring
Source Host Debug
=================================
agent.log.2018-01-24.gz:2018-01-24 13:03:07,822 DEBUG [cloud.agent.Agent]
(UgentTask-5:null) (logid:) Sending ping: Seq 12-111: { Cmd , MgmtId: -1, via:
12, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"_hostVmStateReport":{"i-532-1389-NSVLTN":{"state":"PowerOn","host":"csh01c01z01.nsvltn.ena.net"},"i-532-1392-NSVLTN":{"state":"PowerOn","host":"csh01c01z01.nsvltn.ena.net"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":12,"wait":0}}]
}
Destination Host Agent Debug
=================================
agent.log.2018-01-27.gz:2018-01-27 09:05:46,383 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-2:null) (logid:e4524f82) Request:Seq
22-530861806076297265: { Cmd , MgmtId: 14038012870814, via: 22, Ver: v1,
Flags: 100111,
[{"com.cloud.agent.api.PrepareForMigrationCommand":{"vm":{"id":1392,"name":"i-532-1392-NSVLTN","type":"User","cpus":2,"minSpeed":2000,"maxSpeed":2000,"minRam":4294967296,"maxRam":4294967296,"arch":"x86_64","os":"Other
PV Virtio-SCSI (64-bit)","platformEmulator":"Other PV Virtio-SCSI
(64-bit)","bootArgs":"","enableHA":true,"limitCpuUse":true,"enableDynamicallyScaleVm":false,"vncPassword":"Nj3rVkFUOcN6PWfrtCIfhg","params":{"memoryOvercommitRatio":"1.0","cpuNumber":"2","cpuSpeed":"2000","keyboard":"us","Message.ReservedCapacityFreed.Flag":"false","cpuOvercommitRatio":"2.0","memory":"4096"},"uuid":"f7dbf00b-2e15-4991-a407-cf27a3d65d1e","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"97e5a299-1efd-40ed-85f4-a5c365a56414","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"10a32867-3386-369e-a391-c8e05e0fa8ed","id":22,"poolType":"RBD","host":"cephmonc01.nsvltn.ena.net","path":"c01z01","port":6789,"url":"RBD://cephmonc01.nsvltn.ena.net/c01z01/?ROLE=Primary&STOREUUID=10a32867-3386-369e-a391-c8e05e0fa8ed"}},"name":"DATA-1392","size":2684354560000,"path":"97e5a299-1efd-40ed-85f4-a5c365a56414","volumeId":22732,"vmName":"i-532-1392-NSVLTN","accountId":532,"format":"RAW","provisioningType":"THIN","id":22732,"deviceId":1,"bytesReadRate":524288000,"bytesWriteRate":524288000,"iopsReadRate":500,"iopsWriteRate":500,"hypervisorType":"KVM"}},"diskSeq":1,"path":"97e5a299-1efd-40ed-85f4-a5c365a56414","type":"DATADISK","_details":{"managed":"false","storagePort":"6789","storageHost":"cephmonc01.nsvltn.ena.net","volumeSize":"2684354560000"}},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"223e08b0-929c-4c47-833d-1f1de48610f3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"10a32867-3386-369e-a391-c8e05e0fa8ed","id":22,"poolType":"RBD","host":"cephmonc01.nsvltn.ena.net","path":"c01z01","port":6789,"url":"RBD://cephmonc01.nsvltn.ena.net/c01z01/?ROLE=Primary&STOREUUID=10a32867-3386-369e-a391-c8e05e0fa8ed"}},"name":"ROOT-1392","size":53687091200,"path":"223e08b0-929c-4c47-833d-1f1de48610f3","volumeId":22742,"vmName":"i-532-1392-NSVLTN","accountId":532,"format":"RAW","provisioningType":"THIN","id":22742,"deviceId":0,"bytesReadRate":524288000,"bytesWriteRate":524288000,"iopsReadRate":500,"iopsWriteRate":500,"hypervisorType":"KVM"}},"diskSeq":0,"path":"223e08b0-929c-4c47-833d-1f1de48610f3","type":"ROOT","_details":{"managed":"false","storagePort":"6789","storageHost":"cephmonc01.nsvltn.ena.net","volumeSize":"53687091200"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":1000,"defaultNic":true,"pxeDisable":false,"nicUuid":"27ae6acc-6de0-47b0-86c2-c0ecbdd91a8a","uuid":"bb6caa9c-5cdf-4556-a22f-9fa8c70c1056","ip":"172.16.64.172","netmask":"255.255.255.0","gateway":"172.16.64.1","mac":"02:00:08:da:00:1d","dns1":"207.191.179.90","broadcastType":"Vxlan","type":"Guest","isSecurityGroupEnabled":false,"name":"bond0.3531"}],"configDriveLabel":"config"},"wait":0}}]
}
agent.log.2018-01-27.gz:2018-01-27 09:05:46,388 DEBUG
[kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:e4524f82)
Can not find KVM connection for Instance: i-532-1392-NSVLTN, continuing.
agent.log.2018-01-27.gz:2018-01-27 09:05:46,389 DEBUG
[kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:e4524f82)
Can not find LXC connection for Instance: i-532-1392-NSVLTN, continuing.
agent.log.2018-01-27.gz:2018-01-27 09:05:46,389 WARN
[kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:e4524f82)
Can not find a connection for Instance i-532-1392-NSVLTN. Assuming the default
connection.
Destination Host libvirtd Debug
=================================
230813:2018-01-26 19:36:30.604+0000: 41458: debug : virDomainBlockStats:5400 :
dom=0x7f1c9c0abc00, (VM: name=i-532-1298-NSVLTN,
uuid=d6ec74b8-4f6a-405c-834e-ece42151b802), disk=hdc, stats=0x7f1ca3f53b20,
size=40
230831:2018-01-26 19:36:30.604+0000: 41458: debug :
qemuDomainObjBeginJobInternal:3744 : Starting job: query (vm=0x7f1c3c122d90
name=i-532-1298-NSVLTN, current job=none async=none)
230834:2018-01-26 19:36:30.605+0000: 41458: debug :
qemuDomainObjBeginJobInternal:3785 : Started job: query (async=none
vm=0x7f1c3c122d90 name=i-532-1298-NSVLTN)
230840:2018-01-26 19:36:30.605+0000: 41458: debug :
qemuDomainObjEnterMonitorInternal:4013 : Entering monitor (mon=0x7f1bf0000ee0
vm=0x7f1c3c122d90 name=i-532-1298-NSVLTN)
231419:2018-01-26 19:36:30.609+0000: 41458: debug :
qemuDomainObjExitMonitorInternal:4036 : Exited monitor (mon=0x7f1bf0000ee0
vm=0x7f1c3c122d90 name=i-532-1298-NSVLTN)
231421:2018-01-26 19:36:30.609+0000: 41458: debug : qemuDomainObjEndJob:3944 :
Stopping job: query (async=none vm=0x7f1c3c122d90 name=i-532-1298-NSVLTN)
231431:2018-01-26 19:36:30.609+0000: 41458: debug : virDomainDispose:316 :
release domain 0x7f1c9c0abc00 i-532-1298-NSVLTN
d6ec74b8-4f6a-405c-834e-ece42151b802
