[
https://issues.apache.org/jira/browse/CLOUDSTACK-8830?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15522976#comment-15522976
]
ASF GitHub Bot commented on CLOUDSTACK-8830:
--------------------------------------------
Github user jburwell commented on the issue:
https://github.com/apache/cloudstack/pull/1677
@serg38 I understand it is not an issue on ESXi 5.5. From a regression
test perspective, we need to run to regression tests to ensure this change does
not introduce an issue with ESXi 5.5. Which tests are you running to verify
the change on ESXi 6? I will run those on 5.5 to verify that no regressions
have been introduced.
> [VMware] VM snapshot fails for 12 min after instance creation
> -------------------------------------------------------------
>
> Key: CLOUDSTACK-8830
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-8830
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Reporter: Maneesha
> Assignee: Maneesha
>
> ISSUE
> ============
> [VMware] VM snapshot fails for 12 min after instance creation
> Environment
> ==================
> Product Name: Cloudstack
> Hypervisor: VMWare VSphere 6
> VM DETAILS
> ==================
> i-84987-16119-VM
> TROUBLESHOOTING
> ==================
> I see that the following failure and immediate success result for the
> CreateVMSnapshot call
> {noformat}
> 2015-07-24 08:20:55,363 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-61:ctx-03fad7f2 job-64835/job-64836 ctx-746f3965)
> (logid:8b87ab8a) Seq 80-6161487240196259878: Sending { Cmd , MgmtId:
> 345051581208, via: 80(ussfoldcsesx112.adslab.local), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.CreateVMSnapshotCommand":{"volumeTOs":[{"uuid":"a89b4ad5-f23f-4df6-84a8-89c4f40b2edb","volumeType":"ROOT","volumeState":"Ready","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"346b381a-8543-3f7b-9eff-fa909ad243c7","id":205,"poolType":"NetworkFilesystem","host":"10.144.35.110","path":"/tintri/ECS-SR-CLD200","port":2049,"url":"NetworkFilesystem://10.144.35.110/tintri/ECS-SR-CLD200/?ROLE=Primary&STOREUUID=346b381a-8543-3f7b-9eff-fa909ad243c7"}},"name":"ROOT-16119","size":1073741824,"path":"ROOT-16119","volumeId":19311,"vmName":"i-84987-16119-VM","vmState":"Running","accountId":84987,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[346b381a85433f7b9efffa909ad243c7]
> i-84987-16119-VM/ROOT-16119.vmdk\",\"[346b381a85433f7b9efffa909ad243c7]
> 49f59e1a4ce23fec8890c8b9e5891d56/49f59e1a4ce23fec8890c8b9e5891d56.vmdk\"]}","format":"OVA","provisioningType":"THIN","id":19311,"deviceId":0,"cacheMode":"NONE","hypervisorType":"VMware"}],"target":{"id":962,"snapshotName":"i-84987-16119-VM_VS_20150724152053","type":"Disk","current":false,"description":"unit-test-instance-snapshot","quiescevm":false},"vmName":"i-84987-16119-VM","guestOSType":"None","wait":1800}}]
> }
> 2015-07-24 08:20:55,373 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-61:ctx-03fad7f2 job-64835/job-64836 ctx-746f3965)
> (logid:8b87ab8a) Seq 80-6161487240196259878: Executing: { Cmd , MgmtId:
> 345051581208, via: 80(ussfoldcsesx112.adslab.local), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.CreateVMSnapshotCommand":{"volumeTOs":[{"uuid":"a89b4ad5-f23f-4df6-84a8-89c4f40b2edb","volumeType":"ROOT","volumeState":"Ready","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"346b381a-8543-3f7b-9eff-fa909ad243c7","id":205,"poolType":"NetworkFilesystem","host":"10.144.35.110","path":"/tintri/ECS-SR-CLD200","port":2049,"url":"NetworkFilesystem://10.144.35.110/tintri/ECS-SR-CLD200/?ROLE=Primary&STOREUUID=346b381a-8543-3f7b-9eff-fa909ad243c7"}},"name":"ROOT-16119","size":1073741824,"path":"ROOT-16119","volumeId":19311,"vmName":"i-84987-16119-VM","vmState":"Running","accountId":84987,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[346b381a85433f7b9efffa909ad243c7]
> i-84987-16119-VM/ROOT-16119.vmdk\",\"[346b381a85433f7b9efffa909ad243c7]
> 49f59e1a4ce23fec8890c8b9e5891d56/49f59e1a4ce23fec8890c8b9e5891d56.vmdk\"]}","format":"OVA","provisioningType":"THIN","id":19311,"deviceId":0,"cacheMode":"NONE","hypervisorType":"VMware"}],"target":{"id":962,"snapshotName":"i-84987-16119-VM_VS_20150724152053","type":"Disk","current":false,"description":"unit-test-instance-snapshot","quiescevm":false},"vmName":"i-84987-16119-VM","guestOSType":"None","wait":1800}}]
> }
> 2015-07-24 08:20:55,374 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-66:ctx-5fbdccd8) (logid:710814a5) Seq 80-6161487240196259878:
> Executing request
> 2015-07-24 08:20:55,523 ERROR [c.c.h.v.m.VmwareStorageManagerImpl]
> (DirectAgent-66:ctx-5fbdccd8 ussfoldcsesx112.adslab.local,
> job-64835/job-64836, cmd: CreateVMSnapshotCommand) (logid:8b87ab8a) failed to
> create snapshot for vm:i-84987-16119-VM due to null
> 2015-07-24 08:20:55,524 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-66:ctx-5fbdccd8) (logid:8b87ab8a) Seq 80-6161487240196259878:
> Response Received:
> 2015-07-24 08:20:55,525 DEBUG [c.c.a.t.Request] (DirectAgent-66:ctx-5fbdccd8)
> (logid:8b87ab8a) Seq 80-6161487240196259878: Processing: { Ans: , MgmtId:
> 345051581208, via: 80, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.CreateVMSnapshotAnswer":{"result":false,"wait":0}}] }
> 2015-07-24 08:20:55,525 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-61:ctx-03fad7f2 job-64835/job-64836 ctx-746f3965)
> (logid:8b87ab8a) Seq 80-6161487240196259878: Received: { Ans: , MgmtId:
> 345051581208, via: 80, Ver: v1, Flags: 10, { CreateVMSnapshotAnswer } }
> 2015-07-24 08:20:55,525 ERROR [o.a.c.s.v.DefaultVMSnapshotStrategy]
> (Work-Job-Executor-61:ctx-03fad7f2 job-64835/job-64836 ctx-746f3965)
> (logid:8b87ab8a) Creating VM snapshot: i-84987-16119-VM_VS_20150724152053
> failed
> 2015-07-24 08:20:55,531 DEBUG [c.c.v.s.VMSnapshotManagerImpl]
> (Work-Job-Executor-61:ctx-03fad7f2 job-64835/job-64836 ctx-746f3965)
> (logid:8b87ab8a) Failed to create vm snapshot: 962
> com.cloud.utils.exception.CloudRuntimeException: Creating VM snapshot:
> i-84987-16119-VM_VS_20150724152053 failed
> at
> org.apache.cloudstack.storage.vmsnapshot.DefaultVMSnapshotStrategy.takeVMSnapshot(DefaultVMSnapshotStrategy.java:163)
> at
> com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateCreateVMSnapshot(VMSnapshotManagerImpl.java:438)
> at
> com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateCreateVMSnapshot(VMSnapshotManagerImpl.java:994)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
> at
> com.cloud.vm.snapshot.VMSnapshotManagerImpl.handleVmWorkJob(VMSnapshotManagerImpl.java:1021)
> at sun.reflect.GeneratedMethodAccessor797.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at com.sun.proxy.$Proxy198.handleVmWorkJob(Unknown Source)
> at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:103)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:549)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:500)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> {noformat}
> {noformat}
> 2015-07-24 08:23:01,359 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-137:ctx-bcdafb76) (logid:a20017dd) Seq 80-6161487240196259885:
> Response Received:
> 2015-07-24 08:23:01,370 DEBUG [c.c.a.t.Request]
> (DirectAgent-137:ctx-bcdafb76) (logid:a20017dd) Seq 80-6161487240196259885:
> Processing: { Ans: , MgmtId: 345051581208, via: 80, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.CreateVMSnapshotAnswer":{"volumeTOs":[{"uuid":"a89b4ad5-f23f-4df6-84a8-89c4f40b2edb","volumeType":"ROOT","volumeState":"Ready","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"346b381a-8543-3f7b-9eff-fa909ad243c7","id":205,"poolType":"NetworkFilesystem","host":"10.144.35.110","path":"/tintri/ECS-SR-CLD200","port":2049,"url":"NetworkFilesystem://10.144.35.110/tintri/ECS-SR-CLD200/?ROLE=Primary&STOREUUID=346b381a-8543-3f7b-9eff-fa909ad243c7"}},"name":"ROOT-16119","size":33386,"path":"ROOT-16119-000001","volumeId":19311,"vmName":"i-84987-16119-VM","vmState":"Running","accountId":84987,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[346b381a85433f7b9efffa909ad243c7]
> i-84987-16119-VM/ROOT-16119.vmdk\",\"[346b381a85433f7b9efffa909ad243c7]
> 49f59e1a4ce23fec8890c8b9e5891d56/49f59e1a4ce23fec8890c8b9e5891d56.vmdk\"]}","format":"OVA","provisioningType":"THIN","id":19311,"deviceId":0,"cacheMode":"NONE","hypervisorType":"VMware"}],"vmSnapshotTo":{"id":964,"snapshotName":"i-84987-16119-VM_VS_20150724152253","type":"Disk","current":false,"description":"unit-test-instance-snapshot","quiescevm":false},"result":true,"details":"","wait":0}}]
> }
> 2015-07-24 08:23:01,370 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-63:ctx-f077facb job-64839/job-64840 ctx-85ac1d8c)
> (logid:a20017dd) Seq 80-6161487240196259885: Received: { Ans: , MgmtId:
> 345051581208, via: 80, Ver: v1, Flags: 10, { CreateVMSnapshotAnswer } }
> 2015-07-24 08:23:01,382 DEBUG [o.a.c.s.v.DefaultVMSnapshotStrategy]
> (Work-Job-Executor-63:ctx-f077facb job-64839/job-64840 ctx-85ac1d8c)
> (logid:a20017dd) Create vm snapshot i-84987-16119-VM_VS_20150724152253
> succeeded for vm: i-84987-16119-VM
> 2015-07-24 08:23:01,396 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-63:ctx-f077facb job-64839/job-64840 ctx-85ac1d8c)
> (logid:a20017dd) Done executing VM work job:
> com.cloud.vm.snapshot.VmWorkCreateVMSnapshot{"vmSnapshotId":964,"quiesceVm":false,"userId":1,"accountId":1,"vmId":16119,"handlerName":"VMSnapshotManagerImpl"}
> {noformat}
> It is not clear from this log what is causing this error "failed to create
> snapshot for vm:i-84987-16119-VM due to null"
> Interestingly, this VM has guest OS type set to None (138).
> REPRO STEPS
> ==================
> Try taking snapshot for 12 min after VM creation. VM snapshot fails for 12
> mins after VM creation.
> EXPECTED BEHAVIOR
> ==================
> VM snapshot should be successful from the moment the VM is ready.
> ACTUAL BEHAVIOR
> ==================
> VM snapshot is not successful for ~12 minutes
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
