You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users-cn@cloudstack.apache.org by 虚无缥缈 <83...@qq.com> on 2014/07/17 08:44:29 UTC
vm迁移失败，请帮忙分析。
2014-07-17 14:40:55,451 DEBUG [cloud.capacity.CapacityManagerImpl] (catalina-exec-19:null) Free CPU: 10976 , Requested CPU: 4000
2014-07-17 14:40:55,451 DEBUG [cloud.capacity.CapacityManagerImpl] (catalina-exec-19:null) Free RAM: 72672313344 , Requested RAM: 2147483648
2014-07-17 14:40:55,451 DEBUG [cloud.capacity.CapacityManagerImpl] (catalina-exec-19:null) Host has enough CPU and RAM available
2014-07-17 14:40:55,451 DEBUG [cloud.capacity.CapacityManagerImpl] (catalina-exec-19:null) STATS: Can alloc CPU from host: 42, used: 37000, reserved: 0, actual total: 47976, total with overprovisioning: 47976; requested cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: false
2014-07-17 14:40:55,451 DEBUG [cloud.capacity.CapacityManagerImpl] (catalina-exec-19:null) STATS: Can alloc MEM from host: 42, used: 28722593792, reserved: 0, total: 101394907136; requested mem: 2147483648,alloc_from_last_host?:false ,considerReservedCapacity?: false
2014-07-17 14:40:55,451 DEBUG [allocator.impl.FirstFitAllocator] (catalina-exec-19:null) Found a suitable host, adding to list: 42
2014-07-17 14:40:55,451 DEBUG [allocator.impl.FirstFitAllocator] (catalina-exec-19:null) Host Allocator returning 4 suitable hosts
2014-07-17 14:40:55,452 DEBUG [cloud.server.ManagementServerImpl] (catalina-exec-19:null) Hosts having capacity and suitable for migration: [Host[-43-Routing], Host[-22-Routing], Host[-46-Routing], Host[-42-Routing]]
2014-07-17 14:40:55,506 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===END=== 192.168.8.113 -- GET command=findHostsForMigration&VirtualMachineId=465d2175-2326-4324-acc0-1fa52f477596&response=json&sessionkey=LFCW7IpPHi3Z88DHkqLWn2HGPew%3D&_=1405579265383
2014-07-17 14:40:57,062 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===START=== 192.168.8.113 -- GET command=migrateVirtualMachine&hostid=94faf9f9-e980-4872-badc-7814becc593a&virtualmachineid=465d2175-2326-4324-acc0-1fa52f477596&response=json&sessionkey=LFCW7IpPHi3Z88DHkqLWn2HGPew%3D&_=1405579267077
2014-07-17 14:40:57,086 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-9:null) submit async job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ], details: AsyncJobVO {id:1596, userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd, cmdOriginator: null, cmdInfo: {"response":"json","sessionkey":"LFCW7IpPHi3Z88DHkqLWn2HGPew\u003d","virtualmachineid":"465d2175-2326-4324-acc0-1fa52f477596","cmdEventType":"VM.MIGRATE","hostid":"94faf9f9-e980-4872-badc-7814becc593a","ctxUserId":"2","httpmethod":"GET","_":"1405579267077","ctxAccountId":"2","ctxStartEventId":"5496"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 59716377313896, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-07-17 14:40:57,087 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Executing org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd for job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]
2014-07-17 14:40:57,088 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===END=== 192.168.8.113 -- GET command=migrateVirtualMachine&hostid=94faf9f9-e980-4872-badc-7814becc593a&virtualmachineid=465d2175-2326-4324-acc0-1fa52f477596&response=json&sessionkey=LFCW7IpPHi3Z88DHkqLWn2HGPew%3D&_=1405579267077
2014-07-17 14:40:57,125 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Collect vm disk statistics from host before stopping Vm
2014-07-17 14:40:57,193 DEBUG [agent.transport.Request] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Seq 44-1670981526: Received: { Ans: , MgmtId: 59716377313896, via: 44, Ver: v1, Flags: 10, { GetVmDiskStatsAnswer } }
2014-07-17 14:40:57,193 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Details from executing class com.cloud.agent.api.GetVmDiskStatsCommand:
2014-07-17 14:40:57,197 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Read # of IO that's less than the last one. Assuming something went wrong and persisting it. Host: agent120.test.com . VM: i-8-256-VM Reported: 5340 Stored: 11368
2014-07-17 14:40:57,197 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Write # of IO that's less than the last one. Assuming something went wrong and persisting it. Host: agent120.test.com . VM: i-8-256-VM Reported: 49353 Stored: 141689
2014-07-17 14:40:57,197 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Read # of Bytes that's less than the last one. Assuming something went wrong and persisting it. Host: agent120.test.com . VM: i-8-256-VM Reported: 111934976 Stored: 203096576
2014-07-17 14:40:57,197 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Write # of Bytes that's less than the last one. Assuming something went wrong and persisting it. Host: agent120.test.com . VM: i-8-256-VM Reported: 252018688 Stored: 757862400
2014-07-17 14:40:57,200 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Migrating VM[User|HBASE-H4] to Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(22)-Storage()]
2014-07-17 14:40:57,213 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Service SecurityGroup is not supported in the network id=205
2014-07-17 14:40:57,224 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Service SecurityGroup is not supported in the network id=205
2014-07-17 14:40:57,228 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Preparing 1 volumes for VM[User|HBASE-H4]
2014-07-17 14:40:57,242 DEBUG [storage.image.TemplateDataFactoryImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) template 206 is already in store:1, type:Image
2014-07-17 14:40:57,338 DEBUG [agent.transport.Request] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Seq 22-1086007040: Sending { Cmd , MgmtId: 59716377313896, via: 22, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.PrepareForMigrationCommand":{"vm":{"id":256,"name":"i-8-256-VM","type":"User","cpus":2,"minSpeed":2000,"maxSpeed":2000,"minRam":2147483648,"maxRam":2147483648,"arch":"x86_64","os":"CentOS 6.4 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":true,"limitCpuUse":true,"enableDynamicallyScaleVm":false,"vncPassword":"1448c57f0a527a31","params":{},"uuid":"465d2175-2326-4324-acc0-1fa52f477596","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"81ee95ec-3545-48b4-b001-2da4cacd535a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a05b845b-fbf8-4bc0-af17-868876891ef6","id":29,"poolType":"SharedMountPoint","host":"localhost","path":"/opt/vol-206","port":0}},"name":"ROOT-256","size":21474836480,"path":"a49db507-e722-4329-960f-db9fba335c68","volumeId":250,"vmName":"i-8-256-VM","accountId":8,"format":"QCOW2","id":250,"hypervisorType":"KVM"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/206/206-2-d90ed695-2832-3db1-ba83-24544b289646.iso","origUrl":"http://192.168.150.5/CentOS-6.4-x86_64-bin-DVD1.iso","uuid":"afcfd9c5-0859-417c-b5a9-927bf7be210e","id":206,"format":"ISO","accountId":2,"checksum":"0128cfc7c86072b13ee80dd013e0e5d7","hvm":true,"displayText":"CentOS-6.4-x86_64","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.150.123/vol-189","_role":"Image"}},"name":"206-2-d90ed695-2832-3db1-ba83-24544b289646","hypervisorType":"None"}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"32c3def6-d347-4993-8c85-53b21195dff7","ip":"192.168.153.52","netmask":"255.255.255.0","gateway":"192.168.153.1","mac":"06:04:30:00:00:f5","dns1":"202.106.0.20","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://153","isolationUri":"vlan://153","isSecurityGroupEnabled":false,"name":"cloudbr3"}]},"wait":0}}] }
2014-07-17 14:40:57,447 DEBUG [agent.transport.Request] (AgentManager-Handler-12:null) Seq 22-1086007040: Processing: { Ans: , MgmtId: 59716377313896, via: 22, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: Can't find volume:206-2-d90ed695-2832-3db1-ba83-24544b289646.iso\n\tat com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:147)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.getVolumePath(LibvirtComputingResource.java:3635)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2985)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1196)\n\tat com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat java.lang.Thread.run(Thread.java:744)\n","wait":0}}] }
2014-07-17 14:40:57,447 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-12:null) Seq 22-1086007040: No more commands found
2014-07-17 14:40:57,447 DEBUG [agent.transport.Request] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Seq 22-1086007040: Received: { Ans: , MgmtId: 59716377313896, via: 22, Ver: v1, Flags: 110, { Answer } }
2014-07-17 14:40:57,486 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd
java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.PrepareForMigrationAnswer
at com.cloud.vm.VirtualMachineManagerImpl.migrate(VirtualMachineManagerImpl.java:1544)
at com.cloud.vm.UserVmManagerImpl.migrateVirtualMachine(UserVmManagerImpl.java:3995)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd.execute(MigrateVMCmd.java:147)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
2014-07-17 14:40:57,488 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-126:job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ]) Complete async job-1596 = [ 6f7bacc1-122c-4630-8c66-4fb590910bfe ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.PrepareForMigrationAnswer
2014-07-17 14:40:58,529 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-07-17 14:40:58,567 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
2014-07-17 14:40:58,633 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 48-1548094234: Received: { Ans: , MgmtId: 59716377313896, via: 48, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2014-07-17 14:40:58,656 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 22-1086007041: Received: { Ans: , MgmtId: 59716377313896, via: 22, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2014-07-17 14:40:58,862 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy