cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sailaja Mada (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-4593) [VMWARE] [Upgrade]Livestorage Migration & VM Snapshot features are not fully functional after upgrade
Date Tue, 03 Sep 2013 05:26:53 GMT
Sailaja Mada created CLOUDSTACK-4593:
----------------------------------------

             Summary:  [VMWARE] [Upgrade]Livestorage Migration & VM Snapshot features
are not fully functional after upgrade
                 Key: CLOUDSTACK-4593
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4593
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: Storage Controller, Upgrade, VMware
    Affects Versions: 4.2.1
            Reporter: Sailaja Mada


Steps:

Upgraded setup :

307 Setup with 2 clusters ( Cluster1 – 2 ESXi 5.0 hosts , Cluster2 – Esxi 4.1 host) 

1.	11 Vm’s deployed with 2 VM’s in stopped state 
2.	VM’s with ROOT volume, 2 DATA volumes, 3 DATA volumes 
3.	Snapshots , Template / volumes from this snapshot 
4.	Detached volumes 
5.	Empty volumes which are not attached to any instance 
6.	Cluster with 2 primary storage's 

Upgraded to 4.2  

I got into below failures with VM Snapshot if tried without Stop/Start of the VM Post upgrade
:


2013-09-02 21:35:36,733 WARN  [vmware.resource.VmwareResource] (DirectAgent-320:10.102.192.23)
StartCommand failed due to Exception: java.lang.RuntimeException
Message: File <unspecified filename> was not found

java.lang.RuntimeException: File <unspecified filename> was not found
        at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:378)
        at com.cloud.hypervisor.vmware.mo.VirtualMachineMO.powerOn(VirtualMachineMO.java:188)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2966)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:519)
        at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
        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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-09-02 21:35:36,742 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-320:null) Seq
6-949618439: Response Received:



2013-09-02 21:35:43,972 INFO  [storage.volume.VolumeServiceImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Volume 52 is not referred anywhere, remove it
from volumes table
2013-09-02 21:35:43,981 ERROR [cloud.storage.VolumeManagerImpl] (Job-Executor-75:job-151 =
[ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) migrate volume failed:copy volume from primary to
secondary failed due to exception: Exception: java.lang.Exception
Message: Unable to find related disk device for volume. volume path: ROOT-14-30-000004

2013-09-02 21:35:43,990 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:203] is unreachable:
migrate volume failed: copy volume from primary to secondary failed due to exception: Exception:
java.lang.Exception
Message: Unable to find related disk device for volume. volume path: ROOT-14-30-000004

        at com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2254)
        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
        at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2590)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1948)
        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
        at org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:120)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-09-02 21:35:44,008 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Cleaning up resources for the vm VM[User|instance6withdefaulttempalte]
in Starting state
2013-09-02 21:35:44,009 DEBUG [agent.transport.Request] (Job-Executor-75:job-151 = [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57
]) Seq 8-343475044: Sending  { Cmd , MgmtId: 227594284004867, via: 8, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-14-VM","wait":0}}]
}
2013-09-02 21:35:44,009 DEBUG [agent.transport.Request] (Job-Executor-75:job-151 = [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57
]) Seq 8-343475044: Executing:  { Cmd , MgmtId: 227594284004867, via: 8, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-14-VM","wait":0}}]
}
2013-09-02 21:35:44,010 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-106:null) Seq
8-343475044: Executing request
2013-09-02 21:35:44,010 INFO  [vmware.resource.VmwareResource] (DirectAgent-106:10.102.192.14)
Executing resource StopCommand: {"isProxy":false,"executeInSequence":true,"vmName":"i-3-14-VM","wait":0}


But finally VM got started moving to other host in the cluser: Note : There is no gurantee
that this feature works fine without restart of the VM . After this chain info got updated
(chain_info: {"diskDeviceBusName":"ide0:1","diskChain":["[61105200a56c3a5f9c83783d3d36a9d1]
i-3-14-VM/436fd32b103746d29771a2b10df35cf2.vmdk"]})

2013-09-02 21:35:44,165 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Trying to find a potenial host and associated
storage pools from the suitable host/pool lists for this VM
2013-09-02 21:35:44,165 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Checking if host: 1 can access any suitable storage
pool for volume: ROOT
2013-09-02 21:35:44,166 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Host: 1 can access pool: 201
2013-09-02 21:35:44,168 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Found a potential host id: 1 name: 10.102.192.20
and associated storage pools for this VM
2013-09-02 21:35:44,169 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(30|ROOT-->Pool(201))]
2013-09-02 21:35:44,169 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) Deployment found  - P0=VM[User|instance6withdefaulttempalte],
P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(30|ROOT-->Pool(201))]
2013-09-02 21:35:44,176 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) HostStatsCollector
is running...
2013-09-02 21:35:44,191 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-75:job-151
= [ 3e8e2327-7c56-45ea-a653-ee5b89d75d57 ]) VM state transitted from :Starting to Starting
with event: OperationRetryvm's original host id: 6 new host id: 1 host id before state transition:
8



Second Scenario:

1. Create a VM in 307 

2. Do not perform any stop and start after upgrade to 4.2 

3. Live storage migrate to second cluster , then take a volume snapshot

4. Create the template from this volume snapshot after live storage migration 

5. Try  deployment of the VM using this template.  Deployment works and VM is up & running(
I could login and create files also) .

6. But during deployment there were errors while creating the Volume.  Later it finds one
more storage pool / host and creates volume on this new storage pool. Finally deploy VM works
fine,

ERROR: 

2013-09-02 23:51:11,130 INFO  [storage.volume.VolumeServiceImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) releasing lock for VMTemplateStoragePool 19
2013-09-02 23:51:11,131 WARN  [utils.db.Merovingian2] (Job-Executor-106:job-182 = [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf
]) Was unable to find lock for the key template_spool_ref19 and thread id 1340523980
2013-09-02 23:51:11,131 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Unable to create Vol[59|vm=25|ROOT]:Unable to
copy template to primary storage due to exception:Exception: javax.xml.ws.soap.SOAPFaultException
Message:
Required parameter spec is missing

while parsing call information for method ImportVApp
at line 1, column 110

while parsing SOAP body
at line 1, column 102

while parsing SOAP envelope
at line 1, column 38

while parsing HTTP request for method importVApp
on object of type vim.ResourcePool
at line 1, column 0

2013-09-02 23:51:11,131 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:202] is unreachable:
Unable to create Vol[59|vm=25|ROOT]:Unable to copy template to primary storage due to exception:Exception:
javax.xml.ws.soap.SOAPFaultException
Message:
Required parameter spec is missing

while parsing call information for method ImportVApp
at line 1, column 110

while parsing SOAP body
at line 1, column 102

while parsing SOAP envelope
at line 1, column 38

while parsing HTTP request for method importVApp
on object of type vim.ResourcePool
at line 1, column 0

        at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2544)
        at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2592)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-09-02 23:51:11,139 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Cleaning up resources for the vm VM[User|xxxx]
in Starting state
2013-09-02 23:51:11,141 DEBUG [agent.transport.Request] (Job-Executor-106:job-182 = [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf
]) Seq 6-949618915: Sending  { Cmd , MgmtId: 227594284004867, via: 6, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-25-VM","wait":0}}]
}
2013-09-02 23:51:11,141 DEBUG [agent.transport.Request] (Job-Executor-106:job-182 = [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf
]) Seq 6-949618915: Executing:  { Cmd , MgmtId: 227594284004867, via: 6, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-25-VM","wait":0}}]
}
2013-09-02 23:51:11,141 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-91:null) Seq
6-949618915: Executing request
2013-09-02 23:51:11,141 INFO  [vmware.resource.VmwareResource] (DirectAgent-91:10.102.192.23)
Executing resource StopCommand: {"isProxy":false,"executeInSequence":true,"vmName":"i-3-25-VM","wait"



Deploy VM – PASS:

2013-09-02 23:51:29,848 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-82:null) Seq
2-618137852: Response Received:
2013-09-02 23:51:29,849 DEBUG [agent.transport.Request] (DirectAgent-82:null) Seq 2-618137852:
Processing:  { Ans: , MgmtId: 227594284004867, via: 2, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":25,"name":"i-3-25-VM","bootloader":"HVM","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"hostName":"xxxx","arch":"x86_64","os":"CentOS
5.3 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"95b29c111ca96aee","params":{"nicAdapter":"E1000","vmware.reserve.cpu":"false","nestedVirtualizationFlag":"false","Message.ReservedCapacityFreed.Flag":"false","rootDiskController":"ide","vmware.reserve.mem":"false"},"uuid":"021f2108-2c83-485a-ab6a-e3eab3fc585c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b14d9ecc-0474-4aa7-9b7d-3f8620381e64","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"61105200-a56c-3a5f-9c83-783d3d36a9d1","id":201,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/workps2","port":2049}},"name":"ROOT-25","size":2147483648,"path":"ROOT-25","volumeId":59,"vmName":"i-3-25-VM","accountId":3,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[61105200a56c3a5f9c83783d3d36a9d1]
i-3-25-VM/ROOT-25.vmdk\",\"[61105200a56c3a5f9c83783d3d36a9d1] 6a9fa9a8a4af3849a58167751abc214f/6a9fa9a8a4af3849a58167751abc214f.vmdk\"]}","format":"OVA","id":59,"hypervisorType":"VMware"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"710aa816-6e4a-4f2e-b876-3bb901e881e4","ip":"10.1.1.12","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:4c:e2:00:0c","dns1":"10.103.128.15","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://786","isolationUri":"vlan://786","isSecurityGroupEnabled":false}]},"result":true,"wait":0}}]
}
2013-09-02 23:51:29,849 DEBUG [agent.transport.Request] (Job-Executor-106:job-182 = [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf
]) Seq 2-618137852: Received:  { Ans: , MgmtId: 227594284004867, via: 2, Ver: v1, Flags: 110,
{ StartAnswer } }
2013-09-02 23:51:29,852 DEBUG [agent.manager.AgentAttache] (DirectAgent-82:null) Seq 2-618137852:
No more commands found
2013-09-02 23:51:29,872 INFO  [cloud.storage.VolumeManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Update volume disk chain info. vol: 59, ROOT-25
-> ROOT-25, null -> {"diskDeviceBusName":"ide0:1","diskChain":["[61105200a56c3a5f9c83783d3d36a9d1]
i-3-25-VM/ROOT-25.vmdk","[61105200a56c3a5f9c83783d3d36a9d1] 6a9fa9a8a4af3849a58167751abc214f/6a9fa9a8a4af3849a58167751abc214f.vmdk"]}
2013-09-02 23:51:29,919 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-106:job-182 =
[ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Service SecurityGroup is not supported in the network
id=204
2013-09-02 23:51:29,924 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-106:job-182 =
[ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Service SecurityGroup is not supported in the network
id=204
2013-09-02 23:51:29,931 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) VM state transitted from :Starting to Running
with event: OperationSucceededvm's original host id: 2 new host id: 2 host id before state
transition: 2
2013-09-02 23:51:29,932 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Start completed for VM VM[User|xxxx]
2013-09-02 23:51:29,951 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Complete async job-182 = [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf
], jobStatus: 1, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse@3ac3beea
2013-09-02 23:51:29,963 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-106:job-182
= [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]) Done executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd
for job-182 = [ ed8268f7-bb81-4f02-a94b-3500d4f1d5cf ]




--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message